2020-12-06 16:46:09

by Bean Huo

Subject: [PATCH v1 1/3] scsi: ufs: Distinguish between query REQ and query RSP in query trace

From: Bean Huo <[email protected]>

Currently, in the query completion trace print, since we use
hba->lrb[tag].ucd_req_ptr and didn't differentiate UPIU between
request and response, thus header and transaction-specific field
in UPIU printed by query trace are identical. This is not very
practical. As below:

query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
query_complete: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00

For the failure analysis, we want to understand the real response
reported by the UFS device, however, the current query trace tells
us nothing. After this patch, the query trace on the query_send, and
the above a pair of query_send and query_complete will be:

query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
ufshcd_upiu: HDR:36 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 01 00 00 00 00

Signed-off-by: Bean Huo <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 10 ++++++++--
1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index ceb562accc39..e10de94adb3f 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -321,9 +321,15 @@ static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag,
static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int tag,
const char *str)
{
- struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
+ struct utp_upiu_req *rq_rsp;
+
+ if (!strcmp("query_send", str))
+ 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, &rq->header, &rq->qr);
+ trace_ufshcd_upiu(dev_name(hba->dev), str, &rq_rsp->header,
+ &rq_rsp->qr);
}

static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag,
--
2.17.1

2020-12-06 18:55:35

by Bart Van Assche

Subject: Re: [PATCH v1 1/3] scsi: ufs: Distinguish between query REQ and query RSP in query trace

On 12/6/20 8:42 AM, Bean Huo wrote:
> From: Bean Huo <[email protected]>
>
> Currently, in the query completion trace print, since we use
> hba->lrb[tag].ucd_req_ptr and didn't differentiate UPIU between
> request and response, thus header and transaction-specific field
> in UPIU printed by query trace are identical. This is not very
> practical. As below:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
> query_complete: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
>
> For the failure analysis, we want to understand the real response
> reported by the UFS device, however, the current query trace tells
> us nothing. After this patch, the query trace on the query_send, and
> the above a pair of query_send and query_complete will be:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
> ufshcd_upiu: HDR:36 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 01 00 00 00 00
>
> Signed-off-by: Bean Huo <[email protected]>
> ---
> drivers/scsi/ufs/ufshcd.c | 10 ++++++++--
> 1 file changed, 8 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index ceb562accc39..e10de94adb3f 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -321,9 +321,15 @@ static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> const char *str)
> {
> - struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
> + struct utp_upiu_req *rq_rsp;
> +
> + if (!strcmp("query_send", str))
> + 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, &rq->header, &rq->qr);
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq_rsp->header,
> + &rq_rsp->qr);
> }

Please change the 'str' argument into an enum and let
ufshcd_add_query_upiu_trace() do the enum-to-string conversion. That
will allow to convert the strcmp() call into an integer comparison.

Thanks,

Bart.

2020-12-07 07:49:39

by Avri Altman

Subject: RE: [PATCH v1 1/3] scsi: ufs: Distinguish between query REQ and query RSP in query trace

>
> From: Bean Huo <[email protected]>
>
> Currently, in the query completion trace print, since we use
> hba->lrb[tag].ucd_req_ptr and didn't differentiate UPIU between
> request and response, thus header and transaction-specific field
> in UPIU printed by query trace are identical. This is not very
> practical. As below:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00
> 00 00 00 00 00 00 00 00 00
> query_complete: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00
> 00 00 00 00 00 00 00 00 00 00 00
>
> For the failure analysis, we want to understand the real response
> reported by the UFS device, however, the current query trace tells
> us nothing. After this patch, the query trace on the query_send, and
> the above a pair of query_send and query_complete will be:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00
> 00 00 00 00 00 00 00 00 00
> ufshcd_upiu: HDR:36 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00
> 00 00 00 00 01 00 00 00 00
>
> Signed-off-by: Bean Huo <[email protected]>
Acked-by: Avri Altman <[email protected]>

But you need to change the complete string so not to break the current parsers.
I would also pass to ufshcd_add_query_upiu_trace the struct utp_upiu_req *,
so no comparison is needed.

Thanks,
Avri

> ---
> drivers/scsi/ufs/ufshcd.c | 10 ++++++++--
> 1 file changed, 8 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index ceb562accc39..e10de94adb3f 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -321,9 +321,15 @@ static void ufshcd_add_cmd_upiu_trace(struct
> ufs_hba *hba, unsigned int tag,
> static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int
> tag,
> const char *str)
> {
> - struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
> + struct utp_upiu_req *rq_rsp;
> +
> + if (!strcmp("query_send", str))
> + 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, &rq->header, &rq->qr);
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq_rsp->header,
> + &rq_rsp->qr);
> }
>
> static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int
> tag,
> --
> 2.17.1

2020-12-07 15:27:06

by Steven Rostedt

Subject: Re: [PATCH v1 1/3] scsi: ufs: Distinguish between query REQ and query RSP in query trace

On Sun, 6 Dec 2020 17:42:24 +0100
Bean Huo <[email protected]> wrote:

> From: Bean Huo <[email protected]>
>
> Currently, in the query completion trace print, since we use
> hba->lrb[tag].ucd_req_ptr and didn't differentiate UPIU between
> request and response, thus header and transaction-specific field
> in UPIU printed by query trace are identical. This is not very
> practical. As below:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
> query_complete: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
>
> For the failure analysis, we want to understand the real response
> reported by the UFS device, however, the current query trace tells
> us nothing. After this patch, the query trace on the query_send, and
> the above a pair of query_send and query_complete will be:
>
> query_send: HDR:16 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 00 00 00 00 00
> ufshcd_upiu: HDR:36 00 00 0e 00 81 00 00 00 00 00 00, CDB:06 0e 03 00 00 00 00 00 00 00 00 01 00 00 00 00
>
> Signed-off-by: Bean Huo <[email protected]>
> ---
> drivers/scsi/ufs/ufshcd.c | 10 ++++++++--
> 1 file changed, 8 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index ceb562accc39..e10de94adb3f 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -321,9 +321,15 @@ static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> const char *str)
> {
> - struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
> + struct utp_upiu_req *rq_rsp;
> +

I would add:

if (!trace_ufshcd_upiu_enabled())
return;

Why do the work if the trace point is not enabled?

-- Steve


> + if (!strcmp("query_send", str))
> + 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, &rq->header, &rq->qr);
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq_rsp->header,
> + &rq_rsp->qr);
> }
>
> static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag,

2020-12-08 21:33:51

by Bean Huo

Subject: Re: [PATCH v1 1/3] scsi: ufs: Distinguish between query REQ and query RSP in query trace

On Mon, 2020-12-07 at 10:21 -0500, Steven Rostedt wrote:
> > @@ -321,9 +321,15 @@ static void ufshcd_add_cmd_upiu_trace(struct
> > ufs_hba *hba, unsigned int tag,
> > static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba,
> > unsigned int tag,
> > const char *str)
> > {
> > - struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
> > + struct utp_upiu_req *rq_rsp;
> > +
>
> I would add:
>
> if (!trace_ufshcd_upiu_enabled())
> return;
>
> Why do the work if the trace point is not enabled?
>
> -- Steve

Steve,

Thanks a lot, I will fix it in the next version.


Thanks,
Bean