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

[PATCH v4] 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

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..38743635f2c1 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 v4] scsi: trace: show rtn in string for scsi_dispatch_cmd_error

Posted by James Bottomley 7 months ago

On Tue, 2025-05-20 at 09:59 +0800, 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
> 
> 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..38743635f2c1 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))
> +

This looks much more consistent with the style of the file, thanks;
just make sure the last backslash aligns.

Also, could you assure us you have actually compiled and tested v4?  It
was pretty obvious from the kbuild errors for v2 and v3 that they
hadn't even been compiled.

Regards,

James

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

Posted by Kassey Li quic 7 months ago


On 2025/5/20 23:28, James Bottomley wrote:
> On Tue, 2025-05-20 at 09:59 +0800, 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
>>
>> 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..38743635f2c1 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))
>> +
> 
> This looks much more consistent with the style of the file, thanks;
> just make sure the last backslash aligns.

   manually adjust here is OK ?
   or you need me to re-send out a v5 ?
> 
> Also, could you assure us you have actually compiled and tested v4?  It
> was pretty obvious from the kbuild errors for v2 and v3 that they
> hadn't even been compiled.

   you are right, my compile system did not detect the v2, v3 compile 
error.
   I switched to my hardware platform instead of qemu,  compile the V4, 
flash to my hardware catch the log.
> 
> Regards,
> 
> James
>