[v5] scsi: trace: show rtn in string for scsi_dispatch_cmd_error

[PATCH v5] scsi: trace: show rtn in string for scsi_dispatch_cmd_error

Posted by Kassey Li 7 months ago

By default it showed rtn in decimal:

kworker/3:1H-183 [003] ....  51.035474: scsi_dispatch_cmd_error: host_no=0 channel=0 id=0 lun=4 data_sgl=1  prot_sgl=0 prot_op=SCSI_PROT
_NORMAL cmnd=(READ_10 lba=3907214  txlen=1 protect=0 raw=28 00 00 3b 9e 8e 00 00 01 00) rtn=4181

In source code we define these possible values as hexadecimal:

include/scsi/scsi.h

SCSI_MLQUEUE_HOST_BUSY   0x1055
SCSI_MLQUEUE_DEVICE_BUSY 0x1056
SCSI_MLQUEUE_EH_RETRY    0x1057
SCSI_MLQUEUE_TARGET_BUSY 0x1058

This change shows the rtn in strings:

dd-1059    [007] .....    31.689529: scsi_dispatch_cmd_error: host_no=0 channel=0 id=0 lun=4 data_sgl=65 prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=23 scheduler_tag=117 cmnd=(READ_10 lba=0 txlen=128 protect=0 raw=28 00 00 00 00 00 00 00 80 00) rtn=SCSI_MLQUEUE_DEVICE_BUSY

Changes in v5:
- last backslash aligns.

Signed-off-by: Kassey Li <quic_yingangl@quicinc.com>
---
 include/trace/events/scsi.h | 13 +++++++++++--
 1 file changed, 11 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index 8e2d9b1b0e77..1decb51fbf6e 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -199,6 +199,14 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len))
 );
 
+#define scsi_rtn_name(result)	{ result, #result }
+#define show_rtn_name(val)					\
+	__print_symbolic(val,					\
+		scsi_rtn_name(SCSI_MLQUEUE_HOST_BUSY),		\
+		scsi_rtn_name(SCSI_MLQUEUE_DEVICE_BUSY),	\
+		scsi_rtn_name(SCSI_MLQUEUE_EH_RETRY),		\
+		scsi_rtn_name(SCSI_MLQUEUE_TARGET_BUSY))
+
 TRACE_EVENT(scsi_dispatch_cmd_error,
 
 	TP_PROTO(struct scsi_cmnd *cmd, int rtn),
@@ -239,14 +247,15 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
 
 	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
 		  " prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s)" \
-		  " rtn=%d",
+		  " rtn=%s",
 		  __entry->host_no, __entry->channel, __entry->id,
 		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
 		  show_prot_op_name(__entry->prot_op), __entry->driver_tag,
 		  __entry->scheduler_tag, show_opcode_name(__entry->opcode),
 		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
 		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
-		  __entry->rtn)
+		  show_rtn_name(__entry->rtn)
+	  )
 );
 
 DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
-- 
2.34.1

Re: [PATCH v5] scsi: trace: show rtn in string for scsi_dispatch_cmd_error

Posted by Martin K. Petersen 6 months, 1 week ago

Kassey,

> By default it showed rtn in decimal:
>
> kworker/3:1H-183 [003] .... 51.035474: scsi_dispatch_cmd_error:
> host_no=0 channel=0 id=0 lun=4 data_sgl=1 prot_sgl=0 prot_op=SCSI_PROT
> _NORMAL cmnd=(READ_10 lba=3907214  txlen=1 protect=0 raw=28 00 00 3b 9e 8e 00 00 01 00) rtn=4181

Applied to 6.17/scsi-staging, thanks!

-- 
Martin K. Petersen

Re: [PATCH v5] scsi: trace: show rtn in string for scsi_dispatch_cmd_error

Posted by Kassey Li quic 6 months, 3 weeks ago

hi, James:
	may you review this change ?
BR
Kassey

On 2025/5/21 9:17, Kassey Li wrote:
> By default it showed rtn in decimal:
> 
> kworker/3:1H-183 [003] ....  51.035474: scsi_dispatch_cmd_error: host_no=0 channel=0 id=0 lun=4 data_sgl=1  prot_sgl=0 prot_op=SCSI_PROT
> _NORMAL cmnd=(READ_10 lba=3907214  txlen=1 protect=0 raw=28 00 00 3b 9e 8e 00 00 01 00) rtn=4181
> 
> In source code we define these possible values as hexadecimal:
> 
> include/scsi/scsi.h
> 
> SCSI_MLQUEUE_HOST_BUSY   0x1055
> SCSI_MLQUEUE_DEVICE_BUSY 0x1056
> SCSI_MLQUEUE_EH_RETRY    0x1057
> SCSI_MLQUEUE_TARGET_BUSY 0x1058
> 
> This change shows the rtn in strings:
> 
> dd-1059    [007] .....    31.689529: scsi_dispatch_cmd_error: host_no=0 channel=0 id=0 lun=4 data_sgl=65 prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=23 scheduler_tag=117 cmnd=(READ_10 lba=0 txlen=128 protect=0 raw=28 00 00 00 00 00 00 00 80 00) rtn=SCSI_MLQUEUE_DEVICE_BUSY
> 
> Changes in v5:
> - last backslash aligns.
> 
> Signed-off-by: Kassey Li <quic_yingangl@quicinc.com>
> ---
>   include/trace/events/scsi.h | 13 +++++++++++--
>   1 file changed, 11 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
> index 8e2d9b1b0e77..1decb51fbf6e 100644
> --- a/include/trace/events/scsi.h
> +++ b/include/trace/events/scsi.h
> @@ -199,6 +199,14 @@ TRACE_EVENT(scsi_dispatch_cmd_start,
>   		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len))
>   );
>   
> +#define scsi_rtn_name(result)	{ result, #result }
> +#define show_rtn_name(val)					\
> +	__print_symbolic(val,					\
> +		scsi_rtn_name(SCSI_MLQUEUE_HOST_BUSY),		\
> +		scsi_rtn_name(SCSI_MLQUEUE_DEVICE_BUSY),	\
> +		scsi_rtn_name(SCSI_MLQUEUE_EH_RETRY),		\
> +		scsi_rtn_name(SCSI_MLQUEUE_TARGET_BUSY))
> +
>   TRACE_EVENT(scsi_dispatch_cmd_error,
>   
>   	TP_PROTO(struct scsi_cmnd *cmd, int rtn),
> @@ -239,14 +247,15 @@ TRACE_EVENT(scsi_dispatch_cmd_error,
>   
>   	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
>   		  " prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s)" \
> -		  " rtn=%d",
> +		  " rtn=%s",
>   		  __entry->host_no, __entry->channel, __entry->id,
>   		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
>   		  show_prot_op_name(__entry->prot_op), __entry->driver_tag,
>   		  __entry->scheduler_tag, show_opcode_name(__entry->opcode),
>   		  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
>   		  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
> -		  __entry->rtn)
> +		  show_rtn_name(__entry->rtn)
> +	  )
>   );
>   
>   DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,