diff mbox series

[v2] scsi: trace: change the rtn log in string

Message ID 20250514074456.450006-1-quic_yingangl@quicinc.com
State New
Headers show
Series [v2] scsi: trace: change the rtn log in string | expand

Commit Message

Kassey Li May 14, 2025, 7:44 a.m. UTC
In 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 value 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 string type.

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

Comments

James Bottomley May 14, 2025, 1:39 p.m. UTC | #1
On Wed, 2025-05-14 at 15:44 +0800, Kassey Li wrote:
> In 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 value 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 string type.
> 
> Signed-off-by: Kassey Li <quic_yingangl@quicinc.com>
> ---
>  include/trace/events/scsi.h | 8 ++++++--
>  1 file changed, 6 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/scsi.h
> b/include/trace/events/scsi.h
> index bf6cc98d9122..56987f98ba4a 100644
> --- a/include/trace/events/scsi.h
> +++ b/include/trace/events/scsi.h
> @@ -240,14 +240,18 @@ 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)
> +		  __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY,
> "HOST_BUSY" },
> +			  { SCSI_MLQUEUE_DEVICE_BUSY, "DEVICE_BUSY"
> },
> +			  { SCSI_MLQUEUE_EH_RETRY, "EH_RETRY" },
> +			  { SCSI_MLQUEUE_TARGET_BUSY, "TARGET_BUSY"
> })
> +		  )

We tend to do global print_symbolics as show_XXX_name definitions at
the top of the file even if they only occur once, just in case some
other trace point wants to use them.

Regards,

James
kernel test robot May 14, 2025, 11:05 p.m. UTC | #2
Hi Kassey,

kernel test robot noticed the following build errors:

[auto build test ERROR on trace/for-next]
[also build test ERROR on jejb-scsi/for-next mkp-scsi/for-next linus/master v6.15-rc6 next-20250514]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch#_base_tree_information]

url:    https://github.com/intel-lab-lkp/linux/commits/Kassey-Li/scsi-trace-change-the-rtn-log-in-string/20250514-155034
base:   https://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace for-next
patch link:    https://lore.kernel.org/r/20250514074456.450006-1-quic_yingangl%40quicinc.com
patch subject: [PATCH v2] scsi: trace: change the rtn log in string
config: i386-buildonly-randconfig-001-20250515 (https://download.01.org/0day-ci/archive/20250515/202505150658.uk9oRnKr-lkp@intel.com/config)
compiler: gcc-11 (Debian 11.3.0-12) 11.3.0
reproduce (this is a W=1 build): (https://download.01.org/0day-ci/archive/20250515/202505150658.uk9oRnKr-lkp@intel.com/reproduce)

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <lkp@intel.com>
| Closes: https://lore.kernel.org/oe-kbuild-all/202505150658.uk9oRnKr-lkp@intel.com/

All errors (new ones prefixed by >>):

   In file included from include/trace/define_trace.h:119,
                    from include/trace/events/scsi.h:355,
                    from drivers/scsi/scsi.c:73:
   include/trace/events/scsi.h: In function 'trace_raw_output_scsi_dispatch_cmd_error':
>> include/trace/events/scsi.h:250:36: error: 'rtn' undeclared (first use in this function)
     250 |                   __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
         |                                    ^~~
   include/trace/trace_events.h:219:34: note: in definition of macro 'DECLARE_EVENT_CLASS'
     219 |         trace_event_printf(iter, print);                                \
         |                                  ^~~~~
   include/trace/trace_events.h:45:30: note: in expansion of macro 'PARAMS'
      45 |                              PARAMS(print));                   \
         |                              ^~~~~~
   include/trace/events/scsi.h:203:1: note: in expansion of macro 'TRACE_EVENT'
     203 | TRACE_EVENT(scsi_dispatch_cmd_error,
         | ^~~~~~~~~~~
   include/trace/events/scsi.h:241:9: note: in expansion of macro 'TP_printk'
     241 |         TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
         |         ^~~~~~~~~
   include/trace/events/scsi.h:250:19: note: in expansion of macro '__print_symbolic'
     250 |                   __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
         |                   ^~~~~~~~~~~~~~~~
   include/trace/events/scsi.h:250:36: note: each undeclared identifier is reported only once for each function it appears in
     250 |                   __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
         |                                    ^~~
   include/trace/trace_events.h:219:34: note: in definition of macro 'DECLARE_EVENT_CLASS'
     219 |         trace_event_printf(iter, print);                                \
         |                                  ^~~~~
   include/trace/trace_events.h:45:30: note: in expansion of macro 'PARAMS'
      45 |                              PARAMS(print));                   \
         |                              ^~~~~~
   include/trace/events/scsi.h:203:1: note: in expansion of macro 'TRACE_EVENT'
     203 | TRACE_EVENT(scsi_dispatch_cmd_error,
         | ^~~~~~~~~~~
   include/trace/events/scsi.h:241:9: note: in expansion of macro 'TP_printk'
     241 |         TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
         |         ^~~~~~~~~
   include/trace/events/scsi.h:250:19: note: in expansion of macro '__print_symbolic'
     250 |                   __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
         |                   ^~~~~~~~~~~~~~~~


vim +/rtn +250 include/trace/events/scsi.h

   204	
   205		TP_PROTO(struct scsi_cmnd *cmd, int rtn),
   206	
   207		TP_ARGS(cmd, rtn),
   208	
   209		TP_STRUCT__entry(
   210			__field( unsigned int,	host_no	)
   211			__field( unsigned int,	channel	)
   212			__field( unsigned int,	id	)
   213			__field( unsigned int,	lun	)
   214			__field( int,		rtn	)
   215			__field( unsigned int,	opcode	)
   216			__field( unsigned int,	cmd_len )
   217			__field( int,	driver_tag)
   218			__field( int,	scheduler_tag)
   219			__field( unsigned int,	data_sglen )
   220			__field( unsigned int,	prot_sglen )
   221			__field( unsigned char,	prot_op )
   222			__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
   223		),
   224	
   225		TP_fast_assign(
   226			__entry->host_no	= cmd->device->host->host_no;
   227			__entry->channel	= cmd->device->channel;
   228			__entry->id		= cmd->device->id;
   229			__entry->lun		= cmd->device->lun;
   230			__entry->rtn		= rtn;
   231			__entry->opcode		= cmd->cmnd[0];
   232			__entry->cmd_len	= cmd->cmd_len;
   233			__entry->driver_tag	= scsi_cmd_to_rq(cmd)->tag;
   234			__entry->scheduler_tag	= scsi_cmd_to_rq(cmd)->internal_tag;
   235			__entry->data_sglen	= scsi_sg_count(cmd);
   236			__entry->prot_sglen	= scsi_prot_sg_count(cmd);
   237			__entry->prot_op	= scsi_get_prot_op(cmd);
   238			memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
   239		),
   240	
   241		TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u prot_sgl=%u" \
   242			  " prot_op=%s driver_tag=%d scheduler_tag=%d cmnd=(%s %s raw=%s)" \
   243			  " rtn=%s",
   244			  __entry->host_no, __entry->channel, __entry->id,
   245			  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
   246			  show_prot_op_name(__entry->prot_op), __entry->driver_tag,
   247			  __entry->scheduler_tag, show_opcode_name(__entry->opcode),
   248			  __parse_cdb(__get_dynamic_array(cmnd), __entry->cmd_len),
   249			  __print_hex(__get_dynamic_array(cmnd), __entry->cmd_len),
 > 250			  __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
   251				  { SCSI_MLQUEUE_DEVICE_BUSY, "DEVICE_BUSY" },
   252				  { SCSI_MLQUEUE_EH_RETRY, "EH_RETRY" },
   253				  { SCSI_MLQUEUE_TARGET_BUSY, "TARGET_BUSY" })
   254			  )
   255	);
   256
diff mbox series

Patch

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index bf6cc98d9122..56987f98ba4a 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -240,14 +240,18 @@  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)
+		  __print_symbolic(rtn, { SCSI_MLQUEUE_HOST_BUSY, "HOST_BUSY" },
+			  { SCSI_MLQUEUE_DEVICE_BUSY, "DEVICE_BUSY" },
+			  { SCSI_MLQUEUE_EH_RETRY, "EH_RETRY" },
+			  { SCSI_MLQUEUE_TARGET_BUSY, "TARGET_BUSY" })
+		  )
 );
 
 DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,