From: Bean Huo <[email protected]>
*** BLURB HERE ***
Bean Huo (3):
scsi: ufs: Let UPIU completion trace print RSP UPIU
scsi: ufs: Let command trace only for the cmd != null case
scsi: ufs: Use UPIU query trace in devman_upiu_cmd
drivers/scsi/ufs/ufshcd.c | 64 +++++++++++++++++++++------------------
1 file changed, 35 insertions(+), 29 deletions(-)
--
2.25.1
From: Bean Huo <[email protected]>
Since devman_upiu_cmd is not COMMAND UPIU, and doesn't have
CDB, it is better to use UPIU query trace, which provides more
helpful information for issue shooting.
Signed-off-by: Bean Huo <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 4 ++++
1 file changed, 4 insertions(+)
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index ed9059b3e63d..e8756a4fb972 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -6697,6 +6697,7 @@ static int ufshcd_issue_devman_upiu_cmd(struct ufs_hba *hba,
hba->dev_cmd.complete = &wait;
+ ufshcd_add_query_upiu_trace(hba, UFS_QUERY_SEND, lrbp->ucd_req_ptr);
/* Make sure descriptors are ready before ringing the doorbell */
wmb();
spin_lock_irqsave(hba->host->host_lock, flags);
@@ -6729,6 +6730,9 @@ static int ufshcd_issue_devman_upiu_cmd(struct ufs_hba *hba,
}
}
+ ufshcd_add_query_upiu_trace(hba, err ? UFS_QUERY_ERR : UFS_QUERY_COMP,
+ (struct utp_upiu_req *)lrbp->ucd_rsp_ptr);
+
out:
blk_put_request(req);
out_unlock:
--
2.25.1
From: Bean Huo <[email protected]>
The current UPIU completion event trace still prints the COMMAND UPIU
header, rather than the RSP UPIU header. This makes UPIU command trace
useless in problem shooting in case we receive a trace log from the
customer/field.
There are two important fields in RSP UPIU:
1. The response field, which indicates the UFS defined overall success
or failure of the series of Command, Data and RESPONSE UPIU’s that
make up the execution of a task.
2. The Status field, which contains the command set specific status for
a specific command issued by the initiator device.
Before this patch, the UPIU paired trace events:
ufshcd_upiu: send_req: fe3b0000.ufs: HDR:01 20 00 1c 00 00 00 00 00 00 00 00, CDB:3b e1 00 00 00 00 00 00 30 00 00 00 00 00 00 00
ufshcd_upiu: complete_rsp: fe3b0000.ufs: HDR:01 20 00 1c 00 00 00 00 00 00 00 00, CDB:00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
After the patch:
ufshcd_upiu: send_req: fe3b0000.ufs: HDR:01 20 00 1c 00 00 00 00 00 00 00 00, CDB:3b e1 00 00 00 00 00 00 30 00 00 00 00 00 00 00
ufshcd_upiu: complete_rsp: fe3b0000.ufs: HDR:21 00 00 1c 00 00 00 00 00 00 00 00, CDB:00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Signed-off-by: Bean Huo <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 11 ++++++++---
1 file changed, 8 insertions(+), 3 deletions(-)
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index c382260e0cf7..dc5f13ccf176 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -300,13 +300,18 @@ static void ufshcd_scsi_block_requests(struct ufs_hba *hba)
static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag,
enum ufs_trace_str_t str_t)
{
- struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
+ struct utp_upiu_req *rq_rsp;
if (!trace_ufshcd_upiu_enabled())
return;
- trace_ufshcd_upiu(dev_name(hba->dev), str_t, &rq->header, &rq->sc.cdb,
- UFS_TSF_CDB);
+ if (str_t == UFS_CMD_SEND)
+ rq_rsp = hba->lrb[tag].ucd_req_ptr;
+ else
+ rq_rsp = (struct utp_upiu_req *)hba->lrb[tag].ucd_rsp_ptr;
+
+ trace_ufshcd_upiu(dev_name(hba->dev), str_t, &rq_rsp->header,
+ &rq_rsp->sc.cdb, UFS_TSF_CDB);
}
static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba,
--
2.25.1
From: Bean Huo <[email protected]>
For the query request, we already have query_trace, but in
ufshcd_send_command (), there will add two more redundant
traces. Since lrbp->cmd is null in the query request, the
below these two trace events provide nothing except the tag
and DB. Instead of letting them take up the limited trace
ring buffer, it’s better not to print these traces in case
of cmd == null.
ufshcd_command: send_req: ff3b0000.ufs: tag: 28, DB: 0x0, size: -1, IS: 0, LBA: 18446744073709551615, opcode: 0x0 (0x0), group_id: 0x0
ufshcd_command: dev_complete: ff3b0000.ufs: tag: 28, DB: 0x0, size: -1, IS: 0, LBA: 18446744073709551615, opcode: 0x0 (0x0), group_id: 0x0
Signed-off-by: Bean Huo <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 49 ++++++++++++++++++---------------------
1 file changed, 23 insertions(+), 26 deletions(-)
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index dc5f13ccf176..ed9059b3e63d 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -376,33 +376,31 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag,
struct scsi_cmnd *cmd = lrbp->cmd;
int transfer_len = -1;
- if (!trace_ufshcd_command_enabled()) {
- /* trace UPIU W/O tracing command */
- if (cmd)
- ufshcd_add_cmd_upiu_trace(hba, tag, str_t);
+ if (!cmd)
return;
- }
- if (cmd) { /* data phase exists */
- /* trace UPIU also */
- ufshcd_add_cmd_upiu_trace(hba, tag, str_t);
- opcode = cmd->cmnd[0];
- if ((opcode == READ_10) || (opcode == WRITE_10)) {
- /*
- * Currently we only fully trace read(10) and write(10)
- * commands
- */
- if (cmd->request && cmd->request->bio)
- lba = cmd->request->bio->bi_iter.bi_sector;
- transfer_len = be32_to_cpu(
+ /* trace UPIU W/O tracing command */
+ ufshcd_add_cmd_upiu_trace(hba, tag, str_t);
+
+ if (!trace_ufshcd_command_enabled())
+ return;
+
+ opcode = cmd->cmnd[0];
+ if ((opcode == READ_10) || (opcode == WRITE_10)) {
+ /*
+ * Currently we only fully trace read(10) and write(10)
+ * commands
+ */
+ if (cmd->request && cmd->request->bio)
+ lba = cmd->request->bio->bi_iter.bi_sector;
+ transfer_len = be32_to_cpu(
lrbp->ucd_req_ptr->sc.exp_data_transfer_len);
- if (opcode == WRITE_10)
- group_id = lrbp->cmd->cmnd[6];
- } else if (opcode == UNMAP) {
- if (cmd->request) {
- lba = scsi_get_lba(cmd);
- transfer_len = blk_rq_bytes(cmd->request);
- }
+ if (opcode == WRITE_10)
+ group_id = lrbp->cmd->cmnd[6];
+ } else if (opcode == UNMAP) {
+ if (cmd->request) {
+ lba = scsi_get_lba(cmd);
+ transfer_len = blk_rq_bytes(cmd->request);
}
}
@@ -9774,8 +9772,7 @@ static const struct dev_pm_ops ufs_rpmb_pm_ops = {
};
/**
- * Describes the ufs rpmb wlun.
- * Used only to send uac.
+ * Describes the ufs rpmb wlun. Used only to send uac.
*/
static struct scsi_driver ufs_rpmb_wlun_template = {
.gendrv = {
--
2.25.1
On 5/23/21 2:14 PM, Bean Huo wrote:
> + rq_rsp = (struct utp_upiu_req *)hba->lrb[tag].ucd_rsp_ptr;
So a pointer to a response (hba->lrb[tag].ucd_rsp_ptr) is cast to a
pointer to a request (struct utp_upiu_req *)? That seems really odd to
me. Please explain.
Bart.
On 5/23/21 2:14 PM, Bean Huo wrote:
> + opcode = cmd->cmnd[0];
> + if ((opcode == READ_10) || (opcode == WRITE_10)) {
> + /*
> + * Currently we only fully trace read(10) and write(10)
> + * commands
> + */
> + if (cmd->request && cmd->request->bio)
> + lba = cmd->request->bio->bi_iter.bi_sector;
Why does the lba assignment occur inside the if-statement for the
READ_10 and WRITE_10 cases? Has it been considered to move that
assignment before this if-statement?
Does 'lba' represent an offset in units of 512 bytes (sector_t) or an
LBA (logical block address)? In the former case, please rename the
variable 'lba' into 'sector' or 'start_sector'. In the latter case,
please use sectors_to_logical().
Why are READ_16 and WRITE_16 ignored?
Please remove the 'if (cmd->request)' checks since these are not necessary.
> + } else if (opcode == UNMAP) {
> + if (cmd->request) {
> + lba = scsi_get_lba(cmd);
> + transfer_len = blk_rq_bytes(cmd->request);
> }
> }
The name of the variable 'transfer_len' is wrong since blk_rq_bytes()
returns the number of bytes affected on the storage medium instead of
the number of bytes transferred from the host to the storage controller.
> /**
> - * Describes the ufs rpmb wlun.
> - * Used only to send uac.
> + * Describes the ufs rpmb wlun. Used only to send uac.
> */
Is this change related to the rest of this patch?
Thanks,
Bart.
On 5/23/21 2:14 PM, Bean Huo wrote:
> + ufshcd_add_query_upiu_trace(hba, err ? UFS_QUERY_ERR : UFS_QUERY_COMP,
> + (struct utp_upiu_req *)lrbp->ucd_rsp_ptr);
Why is there a cast in the above code from a response pointer to a
request pointer type?
Thanks,
Bart.
>
> Why are READ_16 and WRITE_16 ignored?
For practical reasons - u32 is large enough to carry addresses for all foreseen devices.
So READ16 is practically not used in ufs, although per spec it is supported.
Bart,
Thanks for your review, appreciated it.
On Sun, 2021-05-23 at 18:32 -0700, Bart Van Assche wrote:
> On 5/23/21 2:14 PM, Bean Huo wrote:
> > + opcode = cmd->cmnd[0];
> > + if ((opcode == READ_10) || (opcode == WRITE_10)) {
> > + /*
> > + * Currently we only fully trace read(10) and write(10)
> > + * commands
> > + */
> > + if (cmd->request && cmd->request->bio)
> > + lba = cmd->request->bio->bi_iter.bi_sector;
>
> Why does the lba assignment occur inside the if-statement for the
> READ_10 and WRITE_10 cases? Has it been considered to move that
> assignment before this if-statement?
yes, this lba assignment can be moved before if-statement:
if (cmd->request && cmd->request->bio)
lba
= cmd->request->bio->bi_iter.bi_sector;
if ((opcode == READ_10) || (opcode == WRITE_10)) {
/*
* Currently we only fully trace read(10) and write(10)
* commands
*/
>
> Does 'lba' represent an offset in units of 512 bytes (sector_t) or an
> LBA (logical block address)? In the former case, please rename the
> variable 'lba' into 'sector' or 'start_sector'. In the latter case,
> please use sectors_to_logical().
apparently it is in 512 bytes. ok, sector is more readable.
>
> Why are READ_16 and WRITE_16 ignored?
READ_16 and WRITE_16 are optimal for the UFS. not mandatory.
>
> Please remove the 'if (cmd->request)' checks since these are not
> necessary.
>
> > + } else if (opcode == UNMAP) {
> > + if (cmd->request) {
> > + lba = scsi_get_lba(cmd);
> > + transfer_len = blk_rq_bytes(cmd->request);
> > }
> > }
>
> The name of the variable 'transfer_len' is wrong since blk_rq_bytes()
> returns the number of bytes affected on the storage medium instead of
> the number of bytes transferred from the host to the storage
> controller.
>
ok, I will remove them, and they will be a additional cleanup patch.
> > /**
> > - * Describes the ufs rpmb wlun.
> > - * Used only to send uac.
> > + * Describes the ufs rpmb wlun. Used only to send uac.
> > */
>
> Is this change related to the rest of this patch?
>
It might be a cleanup.
Bean
> Thanks,
>
> Bart.
On Sun, 2021-05-23 at 18:32 -0700, Bart Van Assche wrote:
> On 5/23/21 2:14 PM, Bean Huo wrote:
>
> > + ufshcd_add_query_upiu_trace(hba, err ? UFS_QUERY_ERR :
> > UFS_QUERY_COMP,
> > + (struct utp_upiu_req *)lrbp-
> > >ucd_rsp_ptr);
>
>
> Why is there a cast in the above code from a response pointer to a
>
> request pointer type?
>
>
Ok, I think it is the same question as one in patch 1/3.
>
> Thanks,
>
>
>
> Bart.
On 5/25/21 12:28 PM, Bean Huo wrote:
> If this is problem, I can change the code, let them more readable.
>
> how do you think?
A long explanation was needed to show that the patch is correct. I think
this shows that the code is confusing :-) Hence please use the struct
utp_upiu_rsp type when interpreting a pointer as a response.
Thanks,
Bart.
On Sun, 2021-05-23 at 18:24 -0700, Bart Van Assche wrote:
> On 5/23/21 2:14 PM, Bean Huo wrote:
>
> > + rq_rsp = (struct utp_upiu_req *)hba-
> > >lrb[tag].ucd_rsp_ptr;
>
>
> So a pointer to a response (hba->lrb[tag].ucd_rsp_ptr) is cast to a
>
> pointer to a request (struct utp_upiu_req *)? That seems really odd
> to
>
> me. Please explain.
Bart,
these two structures have the same size, and inside the structures,
the both unions have the same members(not exactly 100% identical).
struct utp_upiu_rsp {
struct utp_upiu_header header;
union {
struct utp_cmd_rsp sr;
struct utp_upiu_query qr;
};
};
struct utp_upiu_req {
struct utp_upiu_header header;
union {
struct utp_upiu_cmd sc;
struct utp_upiu_query qr;
struct utp_upiu_query uc;
};
};
Use one point for response and request both, no problem here. It is
true that looks very ood, and very difficult to read them.
If this is problem, I can change the code, let them more readable.
how do you think?
Bean