RE: [PATCH v3] scsi: ufs: add trace event for ufs upiu

From: Stanislav Nijnikov
Date: Sun Mar 25 2018 - 09:45:04 EST


Looks fine.

Reviewed-by: Stanislav Nijnikov <stanislav.nijnikov@xxxxxxx>

> -----Original Message-----
> From: Ohad Sharabi [mailto:ohad.sharabi@xxxxxxxxxxx]
> Sent: Sunday, March 25, 2018 10:08 AM
> To: Stanislav Nijnikov <Stanislav.Nijnikov@xxxxxxx>; jejb@xxxxxxxxxxxxxxxxxx; martin.petersen@xxxxxxxxxx;
> gregkh@xxxxxxxxxxxxxxxxxxx
> Cc: linux-scsi@xxxxxxxxxxxxxxx; linux-kernel@xxxxxxxxxxxxxxx; Alex Lemberg <Alex.Lemberg@xxxxxxx>; Ohad Sharabi
> <Ohad.Sharabi@xxxxxxx>
> Subject: [PATCH v3] scsi: ufs: add trace event for ufs upiu
>
> Add UFS Protocol Information Units(upiu) trace events for ufs driver,
> used to trace various ufs transaction types- command, task-management
> and device management.
> The trace-point format is generic and can be easily adapted to trace
> other upius if needed.
> Currently tracing ufs transaction of type 'device management', which
> this patch introduce, cannot be obtained from any other trace.
> Device management transactions are used for communication with the
> device such as reading and writing descriptor or attributes etc.
>
> v2->v3:
> - modify args 3,4 of trace_ufshcd_upiu to be void *
>
> v1->v2:
> - split to transaction specific functions (fix warnings and simplifies
> code)
> - adding traces when sending query command
>
> Signed-off-by: Ohad Sharabi <ohad.sharabi@xxxxxxxxxxx>
> ---
> drivers/scsi/ufs/ufshcd.c | 40 ++++++++++++++++++++++++++++++++++++++++
> include/trace/events/ufs.h | 27 +++++++++++++++++++++++++++
> 2 files changed, 67 insertions(+)
>
> diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
> index c7da2c1..23ffaed 100644
> --- a/drivers/scsi/ufs/ufshcd.c
> +++ b/drivers/scsi/ufs/ufshcd.c
> @@ -274,6 +274,35 @@ static inline void ufshcd_remove_non_printable(char *val)
> *val = ' ';
> }
>
> +static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> + const char *str)
> +{
> + struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr;
> +
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->sc.cdb);
> +}
> +
> +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;
> +
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->qr);
> +}
> +
> +static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag,
> + const char *str)
> +{
> + struct utp_task_req_desc *descp;
> + struct utp_upiu_task_req *task_req;
> + int off = (int)tag - hba->nutrs;
> +
> + descp = &hba->utmrdl_base_addr[off];
> + task_req = (struct utp_upiu_task_req *)descp->task_req_upiu;
> + trace_ufshcd_upiu(dev_name(hba->dev), str, &task_req->header,
> + &task_req->input_param1);
> +}
> +
> static void ufshcd_add_command_trace(struct ufs_hba *hba,
> unsigned int tag, const char *str)
> {
> @@ -283,6 +312,9 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba,
> struct ufshcd_lrb *lrbp;
> int transfer_len = -1;
>
> + /* trace UPIU also */
> + ufshcd_add_cmd_upiu_trace(hba, tag, str);
> +
> if (!trace_ufshcd_command_enabled())
> return;
>
> @@ -2584,6 +2616,7 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba,
>
> hba->dev_cmd.complete = &wait;
>
> + ufshcd_add_query_upiu_trace(hba, tag, "query_send");
> /* Make sure descriptors are ready before ringing the doorbell */
> wmb();
> spin_lock_irqsave(hba->host->host_lock, flags);
> @@ -2593,6 +2626,9 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba,
>
> err = ufshcd_wait_for_dev_cmd(hba, lrbp, timeout);
>
> + ufshcd_add_query_upiu_trace(hba, tag,
> + err ? "query_complete_err" : "query_complete");
> +
> out_put_tag:
> ufshcd_put_dev_cmd_tag(hba, tag);
> wake_up(&hba->dev_cmd.tag_wq);
> @@ -5464,11 +5500,14 @@ static int ufshcd_issue_tm_cmd(struct ufs_hba *hba, int lun_id, int task_id,
>
> spin_unlock_irqrestore(host->host_lock, flags);
>
> + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_send");
> +
> /* wait until the task management command is completed */
> err = wait_event_timeout(hba->tm_wq,
> test_bit(free_slot, &hba->tm_condition),
> msecs_to_jiffies(TM_CMD_TIMEOUT));
> if (!err) {
> + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete_err");
> dev_err(hba->dev, "%s: task management cmd 0x%.2x timed-out\n",
> __func__, tm_function);
> if (ufshcd_clear_tm_cmd(hba, free_slot))
> @@ -5477,6 +5516,7 @@ static int ufshcd_issue_tm_cmd(struct ufs_hba *hba, int lun_id, int task_id,
> err = -ETIMEDOUT;
> } else {
> err = ufshcd_task_req_compl(hba, free_slot, tm_response);
> + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete");
> }
>
> clear_bit(free_slot, &hba->tm_condition);
> diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h
> index bf6f826..f8260e5 100644
> --- a/include/trace/events/ufs.h
> +++ b/include/trace/events/ufs.h
> @@ -257,6 +257,33 @@
> )
> );
>
> +TRACE_EVENT(ufshcd_upiu,
> + TP_PROTO(const char *dev_name, const char *str, void *hdr, void *tsf),
> +
> + TP_ARGS(dev_name, str, hdr, tsf),
> +
> + TP_STRUCT__entry(
> + __string(dev_name, dev_name)
> + __string(str, str)
> + __array(unsigned char, hdr, 12)
> + __array(unsigned char, tsf, 16)
> + ),
> +
> + TP_fast_assign(
> + __assign_str(dev_name, dev_name);
> + __assign_str(str, str);
> + memcpy(__entry->hdr, hdr, sizeof(__entry->hdr));
> + memcpy(__entry->tsf, tsf, sizeof(__entry->tsf));
> + ),
> +
> + TP_printk(
> + "%s: %s: HDR:%s, CDB:%s",
> + __get_str(str), __get_str(dev_name),
> + __print_hex(__entry->hdr, sizeof(__entry->hdr)),
> + __print_hex(__entry->tsf, sizeof(__entry->tsf))
> + )
> +);
> +
> #endif /* if !defined(_TRACE_UFS_H) || defined(TRACE_HEADER_MULTI_READ) */
>
> /* This part must be outside protection */
> --
> 1.9.1