| Message ID | 20230503230654.2441121-1-bvanassche@acm.org |
|---|---|
| Headers | show |
| Series | SCSI core patches | expand |
On 5/4/23 01:06, Bart Van Assche wrote: > If a command fails, SCSI sense data is essential to determine why it > failed. Hence make the sense key, ASC and ASCQ codes available in the > ftrace output. > > Cc: Niklas Cassel <niklas.cassel@wdc.com> > 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 | 21 +++++++++++++++++++-- > 1 file changed, 19 insertions(+), 2 deletions(-) > > diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h > index a2c7befd451a..6c4be1ebe268 100644 > --- a/include/trace/events/scsi.h > +++ b/include/trace/events/scsi.h > @@ -269,9 +269,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; > @@ -285,11 +290,22 @@ 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->sense_buffer && SCSI_SENSE_VALID(cmd) && > + 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; > + } > ), > Hmm. All this business with scsi_normalize_sense(); there are 15 instances calling scsi_normalize_sense(), and half of it are calling it with scmd->sense-buffer. Makes one wonder if we shouldn't add fields in the scmd structure, and do the decoding always... But for another time, I guess. > 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 " > + "sense_key=%u asc=%#x ascq=%#x))", Why two closing braces? > __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 +315,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, Cheers, Hannes
On Wed, May 03, 2023 at 04:06:52PM -0700, Bart Van Assche wrote: > If a command fails, SCSI sense data is essential to determine why it > failed. Hence make the sense key, ASC and ASCQ codes available in the > ftrace output. > > Cc: Niklas Cassel <niklas.cassel@wdc.com> > 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 | 21 +++++++++++++++++++-- > 1 file changed, 19 insertions(+), 2 deletions(-) > > diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h > index a2c7befd451a..6c4be1ebe268 100644 > --- a/include/trace/events/scsi.h > +++ b/include/trace/events/scsi.h > @@ -269,9 +269,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; > @@ -285,11 +290,22 @@ 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->sense_buffer && SCSI_SENSE_VALID(cmd) && > + 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 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 " > + "sense_key=%u asc=%#x ascq=%#x))", With the extra parentheses removed (as mentioned by Hannes): Reviewed-by: Niklas Cassel <niklas.cassel@wdc.com>
Looks good:
Reviewed-by: Christoph Hellwig <hch@lst.de>
On Wed, May 03, 2023 at 04:06:52PM -0700, Bart Van Assche wrote: > If a command fails, SCSI sense data is essential to determine why it > failed. Hence make the sense key, ASC and ASCQ codes available in the > ftrace output. Looks good: Reviewed-by: Christoph Hellwig <hch@lst.de> Although, I'd also love to see pre-decoded ASC and ASCQ codes in the scsi_cmnd at some point.
Looks good:
Reviewed-by: Christoph Hellwig <hch@lst.de>
On 5/4/23 01:07, Hannes Reinecke wrote: > On 5/4/23 01:06, Bart Van Assche wrote: >> 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 " >> + "sense_key=%u asc=%#x ascq=%#x))", > > Why two closing braces? There should only be one closing brace. I will fix this. Thanks, Bart.
Christoph, > Although, I'd also love to see pre-decoded ASC and ASCQ codes in the > scsi_cmnd at some point. Yep! It would be nice to have these readily available.
On 5/8/23 07:05, Benjamin Block wrote: > On Wed, May 03, 2023 at 04:06:52PM -0700, Bart Van Assche wrote: >> @@ -285,11 +290,22 @@ 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->sense_buffer && SCSI_SENSE_VALID(cmd) && > > Can't hurt to have these explicitly here, but these checks are also > done by `scsi_command_normalize_sense()` AFAICT. Niklas requested these checks as a performance optimization. > >> + 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 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 " >> + "sense_key=%u asc=%#x ascq=%#x))", > > In SPC, these are all in base 16, and some existing functions in > `scsi_logging.c` format Sense Key as base 16. We probably should keep > this consistent and also format Sense Key with `%#x`. I can make this change. Thanks, Bart.
On 5/6/23 15:48, Martin K. Petersen wrote: >> Although, I'd also love to see pre-decoded ASC and ASCQ codes in the >> scsi_cmnd at some point. > > Yep! It would be nice to have these readily available. Implementing this seems nontrivial and risky to me. As an example, whether or not scsi_decide_disposition() calls scsi_check_sense() depends on the command result. Guaranteeing that scsi_command_normalize_sense() is called independent of the command result implies moving this call from scsi_check_sense() to somewhere else, e.g. scsi_decide_disposition(). Unfortunately scsi_check_sense() is not only called from the SCSI completion path but also by ATA code that is not related to the SCSI completion path (ata_eh_analyze_tf()). So I consider this change as out-of-scope for this patch series. Bart.