Previous sense messages can be mixed into other sense messages, because continuous printk (KERN_CONT) was used. To avoid the problem, patch d87f3a6f51 introduced a local buffer in Hannes's baranch (*1). But using local buffers can induce stack overflow, so we want to solve the problem without local buffer if possible. trace_seq_printf can add log messages without local buffer, so we use it. (*1) http://git.kernel.org/cgit/linux/kernel/git/hare/scsi-devel.git/log/?h=logging - Result examples <Before> (printk) sd 2:0:0:0: [sda] Sense Key : Medium Error [current] <After> (ftrace) scsi_print_sense: host_no=2 channel=0 id=0 lun=0 [sda] Sense Key (Medium Error [current]) Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@xxxxxxxxxxx> Cc: Hannes Reinecke <hare@xxxxxxx> Cc: Doug Gilbert <dgilbert@xxxxxxxxxxxx> Cc: Martin K. Petersen <martin.petersen@xxxxxxxxxx> Cc: Christoph Hellwig <hch@xxxxxx> Cc: "James E.J. Bottomley" <JBottomley@xxxxxxxxxxxxx> Cc: Hidehiro Kawai <hidehiro.kawai.ez@xxxxxxxxxxx> Cc: Masami Hiramatsu <masami.hiramatsu.pt@xxxxxxxxxxx> --- drivers/scsi/constants.c | 145 ++----------------------------------------- drivers/scsi/scsi_trace.c | 140 ++++++++++++++++++++++++++++++++++++++++-- include/scsi/scsi_eh.h | 7 ++ include/trace/events/scsi.h | 48 ++++++++++++++ 4 files changed, 195 insertions(+), 145 deletions(-) diff --git a/drivers/scsi/constants.c b/drivers/scsi/constants.c index f7b7f32..85b75c8 100644 --- a/drivers/scsi/constants.c +++ b/drivers/scsi/constants.c @@ -19,7 +19,7 @@ #include <scsi/scsi_eh.h> #include <scsi/scsi_dbg.h> - +#include <trace/events/scsi.h> /* Commands with service actions that change the command name */ #define SERVICE_ACTION_IN_12 0xab @@ -1267,58 +1267,8 @@ static const struct error_info2 additional2[] = {0x70, 0x00, 0xff, "Decompression exception short algorithm id of %x"}, {0, 0, 0, NULL} }; - -/* description of the sense key values */ -static const char * const snstext[] = { - "No Sense", /* 0: There is no sense information */ - "Recovered Error", /* 1: The last command completed successfully - but used error correction */ - "Not Ready", /* 2: The addressed target is not ready */ - "Medium Error", /* 3: Data error detected on the medium */ - "Hardware Error", /* 4: Controller or device failure */ - "Illegal Request", /* 5: Error in request */ - "Unit Attention", /* 6: Removable medium was changed, or - the target has been reset, or ... */ - "Data Protect", /* 7: Access to the data is blocked */ - "Blank Check", /* 8: Reached unexpected written or unwritten - region of the medium */ - "Vendor Specific(9)", - "Copy Aborted", /* A: COPY or COMPARE was aborted */ - "Aborted Command", /* B: The target aborted the command */ - "Equal", /* C: A SEARCH DATA command found data equal, - reserved in SPC-4 rev 36 */ - "Volume Overflow", /* D: Medium full with still data to be written */ - "Miscompare", /* E: Source data and data on the medium - do not agree */ - "Completed", /* F: command completed sense data reported, - may occur for successful command */ -}; -#else -static const char * const snstext[] = { - "0x0", "0x1", "0x2", "0x3", "0x4", "0x5", "0x6", "0x7", - "0x8", "0x9", "0xa", "0xb", "0xc", "0xd", "0xe", "0xf", -}; #endif -/* Get sense key string or NULL if not available */ -const char * -scsi_sense_key_string(unsigned char key) { - return snstext[key & 0xf]; -} -EXPORT_SYMBOL(scsi_sense_key_string); - -const char * -scsi_sense_type_string(struct scsi_sense_hdr *sshdr) -{ - return scsi_sense_is_deferred(sshdr) ? "[deferred]" : "[current]"; -} - -const char * -scsi_sense_format_string(struct scsi_sense_hdr *sshdr) -{ - return sshdr->response_code >= 0x72 ? "[descriptor]" : ""; -} - /* * Get additional sense code string or NULL if not available. * This string may contain a "%x" and should be printed with ascq as arg. @@ -1375,105 +1325,22 @@ void scsi_print_sense_hdr(struct scsi_device *sdev, const char *name, struct scsi_sense_hdr *sshdr) { - sdev_printk(KERN_INFO, sdev, "[%s] Sense Key : %s %s%s\n", name, - scsi_sense_key_string(sshdr->sense_key), - scsi_sense_type_string(sshdr), - scsi_sense_format_string(sshdr)); + trace_scsi_print_sense(sdev, name, sshdr, NULL, 0, 0); scsi_show_extd_sense(sdev, name, sshdr->asc, sshdr->ascq); } EXPORT_SYMBOL(scsi_print_sense_hdr); -static void -scsi_dump_sense_buffer(struct scsi_device *sdev, const char *prefix, - const unsigned char *sense_buffer, int sense_len) -{ - char linebuf[128]; - int i, linelen, remaining; - - if (sense_len < 32) - sense_len = 32; - - remaining = sense_len; - for (i = 0; i < sense_len; i += 16) { - linelen = min(remaining, 16); - remaining -= 16; - - hex_dump_to_buffer(sense_buffer + i, linelen, 16, 1, - linebuf, sizeof(linebuf), false); - } - sdev_printk(KERN_INFO, sdev, - "[%s] Unrecognized sense data (in hex): %s", - prefix, linebuf); -} - -static void -scsi_decode_sense_extras(struct scsi_device *sdev, const char *name, - const unsigned char *sense_buffer, int sense_len) -{ - int res, sense_flags = 0, fixed_valid = 0; - u64 info = 0; - char buff[80]; - int blen; - - if ((sense_buffer[0] & 0x80) < 0x72) { - /* decode extras for "fixed" format */ - fixed_valid = sense_buffer[0] & 0x80; - info = get_unaligned_be32(&sense_buffer[3]); - sense_flags = sense_buffer[2]; - } else if (sense_buffer[7] > 0) { - const u8 *ucp; - - /* descriptor format with sense descriptors */ - ucp = scsi_sense_desc_find(sense_buffer, sense_len, 0); - if (ucp) { - fixed_valid = ucp[2] & 0x80; - if (fixed_valid) - info = get_unaligned_be64(&ucp[4]); - } - ucp = scsi_sense_desc_find(sense_buffer, sense_len, 4); - if (ucp) - sense_flags |= ucp[3] & 0xe0; - } - - if (!sense_flags && !fixed_valid) - return; - - res = 0; - memset(buff, 0, sizeof(buff)); - blen = sizeof(buff) - 1; - if (fixed_valid) - res += snprintf(buff + res, blen - res, - "Info fld=0x%llx, ", info); - if (sense_flags) - res += snprintf(buff + res, blen - res, "%s%s%s", - sense_flags & SENSE_FMK ? "FMK, " : "", - sense_flags & SENSE_EOM ? "EOM, " : "", - sense_flags & SENSE_ILI ? "ILI, " : ""); - if (res) { - res -= 2; - buff[res] = '\0'; - } - - sdev_printk(KERN_INFO, sdev, "[%s] %s\n", name, buff); -} - /* Normalize and print sense buffer with name prefix */ void __scsi_print_sense(struct scsi_device *sdev, const char *name, const unsigned char *sense_buffer, int sense_len) { struct scsi_sense_hdr sshdr; + int raw; - if (!scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) { - /* this may be SCSI-1 sense data */ - scsi_dump_sense_buffer(sdev, name, sense_buffer, sense_len); - return; - } + raw = !scsi_normalize_sense(sense_buffer, sense_len, &sshdr); - sdev_printk(KERN_INFO, sdev, "[%s] Sense Key : %s %s%s\n", name, - scsi_sense_key_string(sshdr.sense_key), - scsi_sense_type_string(&sshdr), - scsi_sense_format_string(&sshdr)); - scsi_decode_sense_extras(sdev, name, sense_buffer, sense_len); + trace_scsi_print_sense(sdev, name, &sshdr, sense_buffer, sense_len, + raw); scsi_show_extd_sense(sdev, name, sshdr.asc, sshdr.ascq); } EXPORT_SYMBOL(__scsi_print_sense); diff --git a/drivers/scsi/scsi_trace.c b/drivers/scsi/scsi_trace.c index 6ffbc40..2ecb1dc 100644 --- a/drivers/scsi/scsi_trace.c +++ b/drivers/scsi/scsi_trace.c @@ -17,15 +17,16 @@ */ #include <linux/kernel.h> #include <linux/trace_seq.h> +#include <asm/unaligned.h> #include <trace/events/scsi.h> #include <scsi/scsi_dbg.h> +#include <scsi/scsi_eh.h> #define SERVICE_ACTION16(cdb) (cdb[1] & 0x1f) #define SERVICE_ACTION32(cdb) ((cdb[8] << 8) | cdb[9]) -static const char * -scsi_trace_misc(struct trace_seq *, unsigned char *, int); +static const char *scsi_trace_misc(struct trace_seq *); static const char * scsi_trace_rw6(struct trace_seq *p, unsigned char *cdb, int len) @@ -242,12 +243,12 @@ scsi_trace_varlen(struct trace_seq *p, unsigned char *cdb, int len) case WRITE_SAME_32: return scsi_trace_rw32(p, cdb, len); default: - return scsi_trace_misc(p, cdb, len); + return scsi_trace_misc(p); } } static const char * -scsi_trace_misc(struct trace_seq *p, unsigned char *cdb, int len) +scsi_trace_misc(struct trace_seq *p) { const char *ret = p->buffer + p->len; @@ -285,10 +286,139 @@ scsi_trace_parse_cdb(struct trace_seq *p, unsigned char *cdb, int len) case VARIABLE_LENGTH_CMD: return scsi_trace_varlen(p, cdb, len); default: - return scsi_trace_misc(p, cdb, len); + return scsi_trace_misc(p); } } +#ifdef CONFIG_SCSI_CONSTANTS +/* description of the sense key values */ +static const char * const snstext[] = { + "No Sense", /* 0: There is no sense information */ + "Recovered Error", /* 1: The last command completed successfully + but used error correction */ + "Not Ready", /* 2: The addressed target is not ready */ + "Medium Error", /* 3: Data error detected on the medium */ + "Hardware Error", /* 4: Controller or device failure */ + "Illegal Request", /* 5: Error in request */ + "Unit Attention", /* 6: Removable medium was changed, or + the target has been reset, or ... */ + "Data Protect", /* 7: Access to the data is blocked */ + "Blank Check", /* 8: Reached unexpected written or unwritten + region of the medium */ + "Vendor Specific(9)", + "Copy Aborted", /* A: COPY or COMPARE was aborted */ + "Aborted Command", /* B: The target aborted the command */ + "Equal", /* C: A SEARCH DATA command found data equal, + reserved in SPC-4 rev 36 */ + "Volume Overflow", /* D: Medium full with still data to be written */ + "Miscompare", /* E: Source data and data on the medium + do not agree */ + "Completed", /* F: command completed sense data reported, + may occur for successful command */ +}; +#else +static const char * const snstext[] = { + "0x0", "0x1", "0x2", "0x3", "0x4", "0x5", "0x6", "0x7", + "0x8", "0x9", "0xa", "0xb", "0xc", "0xd", "0xe", "0xf", +}; +#endif + +/* Get sense key string or NULL if not available */ +const char * +scsi_sense_key_string(unsigned char key) { + return snstext[key & 0xf]; +} +EXPORT_SYMBOL(scsi_sense_key_string); + +static const char * +scsi_sense_type_string(u8 res_code) +{ + return __scsi_sense_is_deferred(res_code) ? "[deferred]" : "[current]"; +} + +static const char * +scsi_sense_format_string(u8 res_code) +{ + return res_code >= 0x72 ? "[descriptor]" : ""; +} + +static const char * +scsi_dump_sense_buffer(struct trace_seq *p, const unsigned char *buf, int len) +{ + const char *ret = p->buffer + p->len; + int i; + + if (!buf || !len) + return scsi_trace_misc(p); + + if (len < 32) + len = 32; + + trace_seq_printf(p, "Unrecognized sense data (in hex)"); + for (i = 0; i < len; i += 16) + trace_seq_printf(p, " %02x", buf[i]); + + trace_seq_putc(p, 0); + return ret; +} + +const char * +scsi_trace_decode_sense_extras(struct trace_seq *p, u8 sense_key, u8 res_code, + const unsigned char *buf, int len, int raw) +{ + const char *ret = p->buffer + p->len; + int sense_flags = 0, fixed_valid = 0; + u64 info = 0; + + if (raw) + /* this may be SCSI-1 sense data */ + return scsi_dump_sense_buffer(p, buf, len); + + trace_seq_printf(p, "Sense Key (%s %s%s", + scsi_sense_key_string(sense_key), + scsi_sense_type_string(res_code), + scsi_sense_format_string(res_code)); + + if (!buf || !len) + goto out; + + if ((buf[0] & 0x80) < 0x72) { + /* decode extras for "fixed" format */ + fixed_valid = buf[0] & 0x80; + info = get_unaligned_be32(&buf[3]); + sense_flags = buf[2]; + } else if (buf[7] > 0) { + const u8 *ucp; + + /* descriptor format with sense descriptors */ + ucp = scsi_sense_desc_find(buf, len, 0); + if (ucp) { + fixed_valid = ucp[2] & 0x80; + if (fixed_valid) + info = get_unaligned_be64(&ucp[4]); + } + ucp = scsi_sense_desc_find(buf, len, 4); + if (ucp) + sense_flags |= ucp[3] & 0xe0; + } + + if (!sense_flags && !fixed_valid) + goto out; + + if (fixed_valid) + trace_seq_printf(p, " Info fld=0x%llx", info); + if (sense_flags) + trace_seq_printf(p, " %s%s%s", + sense_flags & SENSE_FMK ? "FMK" : "", + sense_flags & SENSE_EOM ? "EOM" : "", + sense_flags & SENSE_ILI ? "ILI" : ""); + +out: + trace_seq_printf(p, ")"); + trace_seq_putc(p, 0); + return ret; +} + void scsi_show_result(struct scsi_device *sdev, const char *name, int result) { trace_scsi_show_result(sdev, name, result); diff --git a/include/scsi/scsi_eh.h b/include/scsi/scsi_eh.h index 06a8790..0e6d28c 100644 --- a/include/scsi/scsi_eh.h +++ b/include/scsi/scsi_eh.h @@ -47,9 +47,14 @@ extern int scsi_normalize_sense(const u8 *sense_buffer, int sb_len, extern int scsi_command_normalize_sense(struct scsi_cmnd *cmd, struct scsi_sense_hdr *sshdr); +static inline int __scsi_sense_is_deferred(u8 response_code) +{ + return ((response_code >= 0x70) && (response_code & 1)); +} + static inline int scsi_sense_is_deferred(struct scsi_sense_hdr *sshdr) { - return ((sshdr->response_code >= 0x70) && (sshdr->response_code & 1)); + return __scsi_sense_is_deferred(sshdr->response_code); } extern const u8 * scsi_sense_desc_find(const u8 * sense_buffer, int sb_len, diff --git a/include/trace/events/scsi.h b/include/trace/events/scsi.h index 0675195..572aa65 100644 --- a/include/trace/events/scsi.h +++ b/include/trace/events/scsi.h @@ -395,6 +395,54 @@ TRACE_EVENT(scsi_show_result, show_hostbyte_name(host_byte(__entry->result))) ); +const char *scsi_trace_decode_sense_extras(struct trace_seq*, u8, u8, + const unsigned char*, int, int); +#define __decode_extras(sense_key, res_code, buf, len, raw) \ + scsi_trace_decode_sense_extras(p, sense_key, res_code, buf, len, raw) + +TRACE_EVENT(scsi_print_sense, + + TP_PROTO(struct scsi_device *sdev, const char *devname, + struct scsi_sense_hdr *sshdr, + const unsigned char *sense_buffer, int sense_len, int raw), + + TP_ARGS(sdev, devname, sshdr, sense_buffer, sense_len, raw), + + TP_STRUCT__entry( + __field( unsigned int, host_no ) + __field( unsigned int, channel ) + __field( unsigned int, id ) + __field( unsigned int, lun ) + __string(devname, devname ) + __field( u8, sense_key ) + __field( u8, res_code ) + __dynamic_array(unsigned char, sense_buffer, sense_len) + __field( u8, asc ) + __field( u8, ascq ) + __field( int, sense_len ) + __field( int, raw ) + ), + + TP_fast_assign( + __entry->host_no = sdev->host->host_no; + __entry->channel = sdev->channel; + __entry->id = sdev->id; + __entry->lun = sdev->lun; + __assign_str(devname, devname); + __entry->sense_key = sshdr->sense_key; + __entry->res_code = sshdr->response_code; + memcpy(__get_dynamic_array(sense_buffer), sense_buffer, + sense_len); + __entry->sense_len = sense_len; + __entry->raw = raw; + ), + + TP_printk("host_no=%u channel=%u id=%u lun=%u [%s] %s", + __entry->host_no, __entry->channel, __entry->id, __entry->lun, + __get_str(devname), __decode_extras(__entry->sense_key, + __entry->res_code, __get_dynamic_array(sense_buffer), + __entry->sense_len, __entry->raw)) +); #endif /* _TRACE_SCSI_H */ /* This part must be outside protection */ -- To unsubscribe from this list: send the line "unsubscribe linux-scsi" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html