[PATCH 0/4] SCSI core patches

[PATCH 0/4] SCSI core patches

[Bart Van Assche]

Hi Martin,

Please consider these SCSI core patches for the next merge window.

Thanks,

Bart.

Bart Van Assche (4):
  scsi: core: Use min() instead of open-coding it
  scsi: core: Update a source code comment
  scsi: Only kick the requeue list if necessary
  scsi: Trace SCSI sense data

 drivers/scsi/scsi_common.c  |  3 +--
 drivers/scsi/scsi_error.c   |  2 ++
 drivers/scsi/scsi_lib.c     | 16 +++++++++++-----
 include/scsi/scsi_host.h    |  2 +-
 include/trace/events/scsi.h | 17 +++++++++++++++--
 5 files changed, 30 insertions(+), 10 deletions(-)

[PATCH 1/4] scsi: core: Use min() instead of open-coding it

[Bart Van Assche]

From: Bart Van Assche <bvanassche@google.com>

Use min() instead of open-coding it in scsi_normalize_sense().

Cc: Douglas Gilbert <dgilbert@interlog.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
---
 drivers/scsi/scsi_common.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/drivers/scsi/scsi_common.c b/drivers/scsi/scsi_common.c
index 6e50e81a8216..24dec80a6253 100644
--- a/drivers/scsi/scsi_common.c
+++ b/drivers/scsi/scsi_common.c
@@ -176,8 +176,7 @@ bool scsi_normalize_sense(const u8 *sense_buffer, int sb_len,
 		if (sb_len > 2)
 			sshdr->sense_key = (sense_buffer[2] & 0xf);
 		if (sb_len > 7) {
-			sb_len = (sb_len < (sense_buffer[7] + 8)) ?
-					 sb_len : (sense_buffer[7] + 8);
+			sb_len = min(sb_len, sense_buffer[7] + 8);
 			if (sb_len > 12)
 				sshdr->asc = sense_buffer[12];
 			if (sb_len > 13)

[PATCH 2/4] scsi: core: Update a source code comment

[Bart Van Assche]

Make sure that the 'proc_name' comment correctly reflects its new role.

Cc: Christoph Hellwig <hch@lst.de>
Cc: Ming Lei <ming.lei@redhat.com>
Cc: Hannes Reinecke <hare@suse.de>
Cc: John Garry <john.g.garry@oracle.com>
Cc: Mike Christie <michael.christie@oracle.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
---
 include/scsi/scsi_host.h | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/include/scsi/scsi_host.h b/include/scsi/scsi_host.h
index 0f29799efa02..f3e071fd61bd 100644
--- a/include/scsi/scsi_host.h
+++ b/include/scsi/scsi_host.h
@@ -365,7 +365,7 @@ struct scsi_host_template {
 
 
 	/*
-	 * Name of proc directory
+	 * Name reported via the proc_name SCSI host attribute.
 	 */
 	const char *proc_name;
 

Re: [PATCH 2/4] scsi: core: Update a source code comment

[Christoph Hellwig]

Hi Bart, this is the first patch of the series I'm seeing in my
inbox.  It seems like patch 1 and the cover letter got lost,
making a useful review impossible.

Re: [PATCH 2/4] scsi: core: Update a source code comment

[Bart Van Assche]

On 4/27/23 22:38, Christoph Hellwig wrote:
> Hi Bart, this is the first patch of the series I'm seeing in my
> inbox.  It seems like patch 1 and the cover letter got lost,
> making a useful review impossible.

Hi Christoph,

I will Cc you on the entire patch series when I repost it.

Bart.

[PATCH 3/4] scsi: Only kick the requeue list if necessary

[Bart Van Assche]

Instead of running the request queue of each device associated with a
host every 3 ms (BLK_MQ_RESOURCE_DELAY) while host error handling is in
progress, run the request queue after error handling has finished.

Cc: Christoph Hellwig <hch@lst.de>
Cc: Ming Lei <ming.lei@redhat.com>
Cc: Hannes Reinecke <hare@suse.de>
Cc: John Garry <john.g.garry@oracle.com>
Cc: Mike Christie <michael.christie@oracle.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
---
 drivers/scsi/scsi_error.c |  2 ++
 drivers/scsi/scsi_lib.c   | 16 +++++++++++-----
 2 files changed, 13 insertions(+), 5 deletions(-)

diff --git a/drivers/scsi/scsi_error.c b/drivers/scsi/scsi_error.c
index 6bd0cff2a117..62ae100f98ec 100644
--- a/drivers/scsi/scsi_error.c
+++ b/drivers/scsi/scsi_error.c
@@ -2090,6 +2090,8 @@ static void scsi_restart_operations(struct Scsi_Host *shost)
 	 * now that error recovery is done, we will need to ensure that these
 	 * requests are started.
 	 */
+	shost_for_each_device(sdev, shost)
+		blk_mq_kick_requeue_list(sdev->request_queue);
 	scsi_run_host_queues(shost);
 
 	/*
diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
index e59eb0cbfc83..e616730d6295 100644
--- a/drivers/scsi/scsi_lib.c
+++ b/drivers/scsi/scsi_lib.c
@@ -122,11 +122,9 @@ static void scsi_mq_requeue_cmd(struct scsi_cmnd *cmd, unsigned long msecs)
 		WARN_ON_ONCE(true);
 	}
 
-	if (msecs) {
-		blk_mq_requeue_request(rq, false);
+	blk_mq_requeue_request(rq, false);
+	if (!scsi_host_in_recovery(cmd->device->host))
 		blk_mq_delay_kick_requeue_list(rq->q, msecs);
-	} else
-		blk_mq_requeue_request(rq, true);
 }
 
 /**
@@ -165,7 +163,8 @@ static void __scsi_queue_insert(struct scsi_cmnd *cmd, int reason, bool unbusy)
 	 */
 	cmd->result = 0;
 
-	blk_mq_requeue_request(scsi_cmd_to_rq(cmd), true);
+	blk_mq_requeue_request(scsi_cmd_to_rq(cmd),
+			       !scsi_host_in_recovery(cmd->device->host));
 }
 
 /**
@@ -462,6 +461,10 @@ void scsi_requeue_run_queue(struct work_struct *work)
 	scsi_run_queue(q);
 }
 
+/*
+ * Transfer requests from the requeue_list to from where these can be dispatched
+ * and run the request queues.
+ */
 void scsi_run_host_queues(struct Scsi_Host *shost)
 {
 	struct scsi_device *sdev;
@@ -499,6 +502,9 @@ static void scsi_mq_uninit_cmd(struct scsi_cmnd *cmd)
 
 static void scsi_run_queue_async(struct scsi_device *sdev)
 {
+	if (scsi_host_in_recovery(cmd->device->host))
+		return;
+
 	if (scsi_target(sdev)->single_lun ||
 	    !list_empty(&sdev->host->starved_list)) {
 		kblockd_schedule_work(&sdev->requeue_work);

Re: [PATCH 3/4] scsi: Only kick the requeue list if necessary

[kernel test robot]

Hi Bart,

kernel test robot noticed the following build errors:

[auto build test ERROR on mkp-scsi/for-next]
[also build test ERROR on jejb-scsi/for-next linus/master v6.3 next-20230425]
[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/Bart-Van-Assche/scsi-core-Use-min-instead-of-open-coding-it/20230426-073743
base:   https://git.kernel.org/pub/scm/linux/kernel/git/mkp/scsi.git for-next
patch link:    https://lore.kernel.org/r/20230425233446.1231000-4-bvanassche%40acm.org
patch subject: [PATCH 3/4] scsi: Only kick the requeue list if necessary
config: s390-allyesconfig (https://download.01.org/0day-ci/archive/20230426/202304261147.Vx9zYMCi-lkp@intel.com/config)
compiler: s390-linux-gcc (GCC) 12.1.0
reproduce (this is a W=1 build):
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # https://github.com/intel-lab-lkp/linux/commit/1f35bc98f5c39b963f1cbb31159a1e1395dda276
        git remote add linux-review https://github.com/intel-lab-lkp/linux
        git fetch --no-tags linux-review Bart-Van-Assche/scsi-core-Use-min-instead-of-open-coding-it/20230426-073743
        git checkout 1f35bc98f5c39b963f1cbb31159a1e1395dda276
        # save the config file
        mkdir build_dir && cp config build_dir/.config
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-12.1.0 make.cross W=1 O=build_dir ARCH=s390 olddefconfig
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-12.1.0 make.cross W=1 O=build_dir ARCH=s390 SHELL=/bin/bash drivers/scsi/

If you fix the issue, kindly add following tag where applicable
| Reported-by: kernel test robot <lkp@intel.com>
| Link: https://lore.kernel.org/oe-kbuild-all/202304261147.Vx9zYMCi-lkp@intel.com/

All errors (new ones prefixed by >>):

   drivers/scsi/scsi_lib.c: In function 'scsi_run_queue_async':
>> drivers/scsi/scsi_lib.c:509:35: error: 'cmd' undeclared (first use in this function); did you mean 'cma'?
     509 |         if (scsi_host_in_recovery(cmd->device->host))
         |                                   ^~~
         |                                   cma
   drivers/scsi/scsi_lib.c:509:35: note: each undeclared identifier is reported only once for each function it appears in


vim +509 drivers/scsi/scsi_lib.c

   506	
   507	static void scsi_run_queue_async(struct scsi_device *sdev)
   508	{
 > 509		if (scsi_host_in_recovery(cmd->device->host))
   510			return;
   511	
   512		if (scsi_target(sdev)->single_lun ||
   513		    !list_empty(&sdev->host->starved_list)) {
   514			kblockd_schedule_work(&sdev->requeue_work);
   515		} else {
   516			/*
   517			 * smp_mb() present in sbitmap_queue_clear() or implied in
   518			 * .end_io is for ordering writing .device_busy in
   519			 * scsi_device_unbusy() and reading sdev->restarts.
   520			 */
   521			int old = atomic_read(&sdev->restarts);
   522	
   523			/*
   524			 * ->restarts has to be kept as non-zero if new budget
   525			 *  contention occurs.
   526			 *
   527			 *  No need to run queue when either another re-run
   528			 *  queue wins in updating ->restarts or a new budget
   529			 *  contention occurs.
   530			 */
   531			if (old && atomic_cmpxchg(&sdev->restarts, old, 0) == old)
   532				blk_mq_run_hw_queues(sdev->request_queue, true);
   533		}
   534	}
   535	

-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests

Re: [PATCH 3/4] scsi: Only kick the requeue list if necessary

[kernel test robot]

Hi Bart,

kernel test robot noticed the following build errors:

[auto build test ERROR on mkp-scsi/for-next]
[also build test ERROR on jejb-scsi/for-next linus/master v6.3 next-20230425]
[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/Bart-Van-Assche/scsi-core-Use-min-instead-of-open-coding-it/20230426-073743
base:   https://git.kernel.org/pub/scm/linux/kernel/git/mkp/scsi.git for-next
patch link:    https://lore.kernel.org/r/20230425233446.1231000-4-bvanassche%40acm.org
patch subject: [PATCH 3/4] scsi: Only kick the requeue list if necessary
config: i386-randconfig-a013 (https://download.01.org/0day-ci/archive/20230426/202304261310.YvjIbyb4-lkp@intel.com/config)
compiler: clang version 14.0.6 (https://github.com/llvm/llvm-project f28c006a5895fc0e329fe15fead81e37457cb1d1)
reproduce (this is a W=1 build):
        wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
        chmod +x ~/bin/make.cross
        # https://github.com/intel-lab-lkp/linux/commit/1f35bc98f5c39b963f1cbb31159a1e1395dda276
        git remote add linux-review https://github.com/intel-lab-lkp/linux
        git fetch --no-tags linux-review Bart-Van-Assche/scsi-core-Use-min-instead-of-open-coding-it/20230426-073743
        git checkout 1f35bc98f5c39b963f1cbb31159a1e1395dda276
        # save the config file
        mkdir build_dir && cp config build_dir/.config
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 olddefconfig
        COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash drivers/scsi/

If you fix the issue, kindly add following tag where applicable
| Reported-by: kernel test robot <lkp@intel.com>
| Link: https://lore.kernel.org/oe-kbuild-all/202304261310.YvjIbyb4-lkp@intel.com/

All errors (new ones prefixed by >>):

>> drivers/scsi/scsi_lib.c:509:28: error: use of undeclared identifier 'cmd'
           if (scsi_host_in_recovery(cmd->device->host))
                                     ^
   1 error generated.


vim +/cmd +509 drivers/scsi/scsi_lib.c

   506	
   507	static void scsi_run_queue_async(struct scsi_device *sdev)
   508	{
 > 509		if (scsi_host_in_recovery(cmd->device->host))
   510			return;
   511	
   512		if (scsi_target(sdev)->single_lun ||
   513		    !list_empty(&sdev->host->starved_list)) {
   514			kblockd_schedule_work(&sdev->requeue_work);
   515		} else {
   516			/*
   517			 * smp_mb() present in sbitmap_queue_clear() or implied in
   518			 * .end_io is for ordering writing .device_busy in
   519			 * scsi_device_unbusy() and reading sdev->restarts.
   520			 */
   521			int old = atomic_read(&sdev->restarts);
   522	
   523			/*
   524			 * ->restarts has to be kept as non-zero if new budget
   525			 *  contention occurs.
   526			 *
   527			 *  No need to run queue when either another re-run
   528			 *  queue wins in updating ->restarts or a new budget
   529			 *  contention occurs.
   530			 */
   531			if (old && atomic_cmpxchg(&sdev->restarts, old, 0) == old)
   532				blk_mq_run_hw_queues(sdev->request_queue, true);
   533		}
   534	}
   535	

-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests

[PATCH 4/4] scsi: Trace SCSI sense data

[Bart Van Assche]

If a command fails, SCSI sense data is essential to determine why it
failed. Hence make the SCSI sense data available in the ftrace output.

Cc: Christoph Hellwig <hch@lst.de>
Cc: Ming Lei <ming.lei@redhat.com>
Cc: Hannes Reinecke <hare@suse.de>
Cc: John Garry <john.g.garry@oracle.com>
Cc: Mike Christie <michael.christie@oracle.com>
Signed-off-by: Bart Van Assche <bvanassche@acm.org>
---
 include/trace/events/scsi.h | 17 +++++++++++++++--
 1 file changed, 15 insertions(+), 2 deletions(-)

diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index a2c7befd451a..bb5f31504fbb 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -269,6 +269,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__field( unsigned int,	prot_sglen )
 		__field( unsigned char,	prot_op )
 		__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
+		__array(unsigned char,  sense_data, SCSI_SENSE_BUFFERSIZE)
 	),
 
 	TP_fast_assign(
@@ -285,11 +286,13 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
 		__entry->prot_op	= scsi_get_prot_op(cmd);
 		memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
+		memcpy(__entry->sense_data, cmd->sense_buffer,
+		       SCSI_SENSE_BUFFERSIZE);
 	),
 
 	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) " \
-		  "result=(driver=%s host=%s message=%s status=%s)",
+		  "result=(driver=%s host=%s message=%s status=%s%s%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,
@@ -299,7 +302,17 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
 		  "DRIVER_OK",
 		  show_hostbyte_name(((__entry->result) >> 16) & 0xff),
 		  "COMMAND_COMPLETE",
-		  show_statusbyte_name(__entry->result & 0xff))
+		  show_statusbyte_name(__entry->result & 0xff),
+		  __entry->result & 0xff ? " sense_data=" : "",
+		  __entry->result & 0xff ?
+		  ({
+			  unsigned int len = SCSI_SENSE_BUFFERSIZE;
+
+			  while (len && __entry->sense_data[len - 1] == 0)
+				  len--;
+			  __print_hex(__entry->sense_data, len);
+		  })
+		  : "")
 );
 
 DEFINE_EVENT(scsi_cmd_done_timeout_template, scsi_dispatch_cmd_done,

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Steven Rostedt]

On Tue, 25 Apr 2023 16:34:46 -0700
Bart Van Assche <bvanassche@acm.org> wrote:

> If a command fails, SCSI sense data is essential to determine why it
> failed. Hence make the SCSI sense data available in the ftrace output.
> 
> Cc: Christoph Hellwig <hch@lst.de>
> Cc: Ming Lei <ming.lei@redhat.com>
> Cc: Hannes Reinecke <hare@suse.de>
> Cc: John Garry <john.g.garry@oracle.com>
> Cc: Mike Christie <michael.christie@oracle.com>
> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
> ---
>  include/trace/events/scsi.h | 17 +++++++++++++++--
>  1 file changed, 15 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
> index a2c7befd451a..bb5f31504fbb 100644
> --- a/include/trace/events/scsi.h
> +++ b/include/trace/events/scsi.h
> @@ -269,6 +269,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__field( unsigned int,	prot_sglen )
>  		__field( unsigned char,	prot_op )
>  		__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
> +		__array(unsigned char,  sense_data, SCSI_SENSE_BUFFERSIZE)
>  	),
>  
>  	TP_fast_assign(
> @@ -285,11 +286,13 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
>  		__entry->prot_op	= scsi_get_prot_op(cmd);
>  		memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
> +		memcpy(__entry->sense_data, cmd->sense_buffer,
> +		       SCSI_SENSE_BUFFERSIZE);
>  	),
>  
>  	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) " \
> -		  "result=(driver=%s host=%s message=%s status=%s)",
> +		  "result=(driver=%s host=%s message=%s status=%s%s%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,
> @@ -299,7 +302,17 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		  "DRIVER_OK",
>  		  show_hostbyte_name(((__entry->result) >> 16) & 0xff),
>  		  "COMMAND_COMPLETE",
> -		  show_statusbyte_name(__entry->result & 0xff))
> +		  show_statusbyte_name(__entry->result & 0xff),
> +		  __entry->result & 0xff ? " sense_data=" : "",
> +		  __entry->result & 0xff ?
> +		  ({
> +			  unsigned int len = SCSI_SENSE_BUFFERSIZE;
> +
> +			  while (len && __entry->sense_data[len - 1] == 0)
> +				  len--;
> +			  __print_hex(__entry->sense_data, len);
> +		  })

The above will absolutely break user space parsing.

The TP_printk() isn't supposed to be too complex, as user space uses it to
figure out how to parse the data.

If you are doing the above, I'm guessing that most of the time the
sense_data doesn't use the 96 bytes (defined by SCSI_SENSE_BUFFERSIZE).

Perhaps instead, you should make result a dynamic array, and save writing
a large amount of zeros into the precious ring buffer?

static int sense_data_size(unsigned char *array)
{
	int len = SCSI_SENSE_BUFFERSIZE;

	for (len && array[len - 1] == 0)
		len--;

	return len;
}

		__dynamic_array(unsigned char, sense_data, result_size(cmd->sense_data)

	[..]


		memcpy(__get_dynamic_array(sense_data), cmd->sense_data, result_size(cmd->sense_data));

// Yes, I need a way to pass the "result_size" from the initialization to
// the allocation.


	[..]


		__print_hex(__get_dynamic_array(sense_data),
			    __get_dynamic_array_len(sense_data))

Or something like that.

-- Steve


> +		  : "")
>  );
>  
>  DEFINE_EVENT(scsi_cmd_done_timeout_template, scsi_dispatch_cmd_done,

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Niklas Cassel]

On Tue, Apr 25, 2023 at 04:34:46PM -0700, Bart Van Assche wrote:
> If a command fails, SCSI sense data is essential to determine why it
> failed. Hence make the SCSI sense data available in the ftrace output.
> 
> Cc: Christoph Hellwig <hch@lst.de>
> Cc: Ming Lei <ming.lei@redhat.com>
> Cc: Hannes Reinecke <hare@suse.de>
> Cc: John Garry <john.g.garry@oracle.com>
> Cc: Mike Christie <michael.christie@oracle.com>
> Signed-off-by: Bart Van Assche <bvanassche@acm.org>
> ---
>  include/trace/events/scsi.h | 17 +++++++++++++++--
>  1 file changed, 15 insertions(+), 2 deletions(-)
> 
> diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
> index a2c7befd451a..bb5f31504fbb 100644
> --- a/include/trace/events/scsi.h
> +++ b/include/trace/events/scsi.h
> @@ -269,6 +269,7 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__field( unsigned int,	prot_sglen )
>  		__field( unsigned char,	prot_op )
>  		__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
> +		__array(unsigned char,  sense_data, SCSI_SENSE_BUFFERSIZE)
>  	),
>  
>  	TP_fast_assign(
> @@ -285,11 +286,13 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
>  		__entry->prot_op	= scsi_get_prot_op(cmd);
>  		memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
> +		memcpy(__entry->sense_data, cmd->sense_buffer,
> +		       SCSI_SENSE_BUFFERSIZE);
>  	),
>  
>  	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) " \
> -		  "result=(driver=%s host=%s message=%s status=%s)",
> +		  "result=(driver=%s host=%s message=%s status=%s%s%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,
> @@ -299,7 +302,17 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		  "DRIVER_OK",
>  		  show_hostbyte_name(((__entry->result) >> 16) & 0xff),
>  		  "COMMAND_COMPLETE",
> -		  show_statusbyte_name(__entry->result & 0xff))
> +		  show_statusbyte_name(__entry->result & 0xff),
> +		  __entry->result & 0xff ? " sense_data=" : "",
> +		  __entry->result & 0xff ?
> +		  ({
> +			  unsigned int len = SCSI_SENSE_BUFFERSIZE;
> +
> +			  while (len && __entry->sense_data[len - 1] == 0)
> +				  len--;
> +			  __print_hex(__entry->sense_data, len);

Hello Bart,

Do we really need to dump the whole sense buffer?

Shouldn't simply printing the SK, ASC, ASCQ be sufficient?

Yes, it is a bit annoying that there are two different formats.
But you could do the reverse of:
https://github.com/torvalds/linux/blob/v6.3/drivers/scsi/scsi_common.c#L241

Or, if the tracepoint is after scsi_normalize_sense() has been called,
you could simply use sshdr->sense_key, sshdr->asc and sshdr->ascq.


Kind regards,
Niklas

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Bart Van Assche]

On 4/28/23 01:09, Niklas Cassel wrote:
> Do we really need to dump the whole sense buffer?
> 
> Shouldn't simply printing the SK, ASC, ASCQ be sufficient?
Hi Niklas,

How about replacing patch 4/4 of this series with the patch below?

Thanks,

Bart.



diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
index 370ade0d4093..d4a27cd4040b 100644
--- a/include/trace/events/scsi.h
+++ b/include/trace/events/scsi.h
@@ -258,9 +258,14 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
  		__field( unsigned int,	prot_sglen )
  		__field( unsigned char,	prot_op )
  		__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
+		__field( u8, sense_key )
+		__field( u8, asc )
+		__field( u8, ascq )
  	),

  	TP_fast_assign(
+		struct scsi_sense_hdr sshdr;
+
  		__entry->host_no	= cmd->device->host->host_no;
  		__entry->channel	= cmd->device->channel;
  		__entry->id		= cmd->device->id;
@@ -272,11 +277,21 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
  		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
  		__entry->prot_op	= scsi_get_prot_op(cmd);
  		memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
+		if (cmd->result & 0xff &&
+		    scsi_command_normalize_sense(cmd, &sshdr)) {
+			__entry->sense_key = sshdr.sense_key;
+			__entry->asc = sshdr.asc;
+			__entry->ascq = sshdr.ascq;
+		} else {
+			__entry->sense_key = 0;
+			__entry->asc = 0;
+			__entry->ascq = 0;
+		}
  	),

  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
  		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \
-		  "%s host=%s message=%s status=%s)",
+		  "%s host=%s message=%s status=%s sense_key=%u asc=%#x ascq=%#x)",
  		  __entry->host_no, __entry->channel, __entry->id,
  		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
  		  show_prot_op_name(__entry->prot_op),
@@ -286,7 +301,8 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
  		  "DRIVER_OK",
  		  show_hostbyte_name(((__entry->result) >> 16) & 0xff),
  		  "COMMAND_COMPLETE",
-		  show_statusbyte_name(__entry->result & 0xff))
+		  show_statusbyte_name(__entry->result & 0xff),
+		  __entry->sense_key, __entry->asc, __entry->ascq)
  );

  DEFINE_EVENT(scsi_cmd_done_timeout_template, scsi_dispatch_cmd_done,

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Niklas Cassel]

On Fri, Apr 28, 2023 at 11:36:29AM -0700, Bart Van Assche wrote:
> On 4/28/23 01:09, Niklas Cassel wrote:
> > Do we really need to dump the whole sense buffer?
> > 
> > Shouldn't simply printing the SK, ASC, ASCQ be sufficient?
> Hi Niklas,
> 
> How about replacing patch 4/4 of this series with the patch below?
> 
> Thanks,
> 
> Bart.
> 
> 
> 
> diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h
> index 370ade0d4093..d4a27cd4040b 100644
> --- a/include/trace/events/scsi.h
> +++ b/include/trace/events/scsi.h
> @@ -258,9 +258,14 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__field( unsigned int,	prot_sglen )
>  		__field( unsigned char,	prot_op )
>  		__dynamic_array(unsigned char,	cmnd, cmd->cmd_len)
> +		__field( u8, sense_key )
> +		__field( u8, asc )
> +		__field( u8, ascq )
>  	),
> 
>  	TP_fast_assign(
> +		struct scsi_sense_hdr sshdr;
> +
>  		__entry->host_no	= cmd->device->host->host_no;
>  		__entry->channel	= cmd->device->channel;
>  		__entry->id		= cmd->device->id;
> @@ -272,11 +277,21 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		__entry->prot_sglen	= scsi_prot_sg_count(cmd);
>  		__entry->prot_op	= scsi_get_prot_op(cmd);
>  		memcpy(__get_dynamic_array(cmnd), cmd->cmnd, cmd->cmd_len);
> +		if (cmd->result & 0xff &&
> +		    scsi_command_normalize_sense(cmd, &sshdr)) {

Looks good to me, but considering that a command can be SAM_STAT_GOOD
(which is defined as 0x00), and still have sense data (e.g. CDL policy 0xD
timeout), perhaps you could use the same check as in:
https://lore.kernel.org/linux-ide/20230406113252.41211-1-nks@flawful.org/T/#me609b85c48b4048561662b0a4b1d102e19d7a13d

i.e., something like:
	if (cmd->sense_buffer && SCSI_SENSE_VALID(cmd) &&
	    scsi_command_normalize_sense(cmd, &sshdr)) {

instead of cmd->result & 0xff.

(Yes, I know that the CDL series is not merged yet, but the point is that a
SCSI command can be SAM_STAT_GOOD and still have valid sense data.)


Kind regards,
Niklas


> +			__entry->sense_key = sshdr.sense_key;
> +			__entry->asc = sshdr.asc;
> +			__entry->ascq = sshdr.ascq;
> +		} else {
> +			__entry->sense_key = 0;
> +			__entry->asc = 0;
> +			__entry->ascq = 0;
> +		}
>  	),
> 
>  	TP_printk("host_no=%u channel=%u id=%u lun=%u data_sgl=%u " \
>  		  "prot_sgl=%u prot_op=%s cmnd=(%s %s raw=%s) result=(driver=" \
> -		  "%s host=%s message=%s status=%s)",
> +		  "%s host=%s message=%s status=%s sense_key=%u asc=%#x ascq=%#x)",
>  		  __entry->host_no, __entry->channel, __entry->id,
>  		  __entry->lun, __entry->data_sglen, __entry->prot_sglen,
>  		  show_prot_op_name(__entry->prot_op),
> @@ -286,7 +301,8 @@ DECLARE_EVENT_CLASS(scsi_cmd_done_timeout_template,
>  		  "DRIVER_OK",
>  		  show_hostbyte_name(((__entry->result) >> 16) & 0xff),
>  		  "COMMAND_COMPLETE",
> -		  show_statusbyte_name(__entry->result & 0xff))
> +		  show_statusbyte_name(__entry->result & 0xff),
> +		  __entry->sense_key, __entry->asc, __entry->ascq)
>  );
> 
>  DEFINE_EVENT(scsi_cmd_done_timeout_template, scsi_dispatch_cmd_done,
> 

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Bart Van Assche]

On 5/2/23 02:52, Niklas Cassel wrote:
> i.e., something like:
> 	if (cmd->sense_buffer && SCSI_SENSE_VALID(cmd) &&
> 	    scsi_command_normalize_sense(cmd, &sshdr)) {
> 
> instead of cmd->result & 0xff.

Hmm ... doesn't the SCSI_SENSE_VALID() check above duplicate the
scsi_sense_valid() check inside scsi_command_normalize_sense()?

Thanks,

Bart.

Re: [PATCH 4/4] scsi: Trace SCSI sense data

[Niklas Cassel]

On Tue, May 02, 2023 at 01:31:10PM -0700, Bart Van Assche wrote:
> On 5/2/23 02:52, Niklas Cassel wrote:
> > i.e., something like:
> > 	if (cmd->sense_buffer && SCSI_SENSE_VALID(cmd) &&
> > 	    scsi_command_normalize_sense(cmd, &sshdr)) {
> > 
> > instead of cmd->result & 0xff.
> 
> Hmm ... doesn't the SCSI_SENSE_VALID() check above duplicate the
> scsi_sense_valid() check inside scsi_command_normalize_sense()?

scsi_command_normalize_sense() calls scsi_normalize_sense(),
so that is a function call.

scsi_normalize_sense() then performs a memset(),
a null pointer check on sense_buffer, and length check on sb_len,
then assigns sshdr->response_code, then calls scsi_sense_valid(),
and returns if not valid.


Considering that this tracepoint is called by scsi_done_internal(),
this tracepoint will be called for all SCSI commands (and not just
timed out commands).

I'm not sure how much overhead the function call, memset, and
assignment is, but I would guess that it is not free, and since
this is done for all commands, I would assume that we waste less
CPU cycles by simply checking SCSI_SENSE_VALID() beforehand.


Kind regards,
Niklas