diff options
Diffstat (limited to 'drivers/scsi/scsi_logging.c')
| -rw-r--r-- | drivers/scsi/scsi_logging.c | 485 |
1 files changed, 485 insertions, 0 deletions
diff --git a/drivers/scsi/scsi_logging.c b/drivers/scsi/scsi_logging.c new file mode 100644 index 00000000000..bd70339c124 --- /dev/null +++ b/drivers/scsi/scsi_logging.c @@ -0,0 +1,485 @@ +/* + * scsi_logging.c + * + * Copyright (C) 2014 SUSE Linux Products GmbH + * Copyright (C) 2014 Hannes Reinecke <hare@suse.de> + * + * This file is released under the GPLv2 + */ + +#include <linux/kernel.h> +#include <linux/atomic.h> + +#include <scsi/scsi.h> +#include <scsi/scsi_cmnd.h> +#include <scsi/scsi_device.h> +#include <scsi/scsi_eh.h> +#include <scsi/scsi_dbg.h> + +#define SCSI_LOG_SPOOLSIZE 4096 + +#if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG +#warning SCSI logging bitmask too large +#endif + +struct scsi_log_buf { + char buffer[SCSI_LOG_SPOOLSIZE]; + unsigned long map; +}; + +static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log); + +static char *scsi_log_reserve_buffer(size_t *len) +{ + struct scsi_log_buf *buf; + unsigned long map_bits = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE; + unsigned long idx = 0; + + preempt_disable(); + buf = this_cpu_ptr(&scsi_format_log); + idx = find_first_zero_bit(&buf->map, map_bits); + if (likely(idx < map_bits)) { + while (test_and_set_bit(idx, &buf->map)) { + idx = find_next_zero_bit(&buf->map, map_bits, idx); + if (idx >= map_bits) + break; + } + } + if (WARN_ON(idx >= map_bits)) { + preempt_enable(); + return NULL; + } + *len = SCSI_LOG_BUFSIZE; + return buf->buffer + idx * SCSI_LOG_BUFSIZE; +} + +static void scsi_log_release_buffer(char *bufptr) +{ + struct scsi_log_buf *buf; + unsigned long idx; + int ret; + + buf = this_cpu_ptr(&scsi_format_log); + if (bufptr >= buf->buffer && + bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) { + idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE; + ret = test_and_clear_bit(idx, &buf->map); + WARN_ON(!ret); + } + preempt_enable(); +} + +static inline const char *scmd_name(const struct scsi_cmnd *scmd) +{ + return scmd->request->rq_disk ? + scmd->request->rq_disk->disk_name : NULL; +} + +static size_t sdev_format_header(char *logbuf, size_t logbuf_len, + const char *name, int tag) +{ + size_t off = 0; + + if (name) + off += scnprintf(logbuf + off, logbuf_len - off, + "[%s] ", name); + + if (WARN_ON(off >= logbuf_len)) + return off; + + if (tag >= 0) + off += scnprintf(logbuf + off, logbuf_len - off, + "tag#%d ", tag); + return off; +} + +void sdev_prefix_printk(const char *level, const struct scsi_device *sdev, + const char *name, const char *fmt, ...) +{ + va_list args; + char *logbuf; + size_t off = 0, logbuf_len; + + if (!sdev) + return; + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + + if (name) + off += scnprintf(logbuf + off, logbuf_len - off, + "[%s] ", name); + if (!WARN_ON(off >= logbuf_len)) { + va_start(args, fmt); + off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); + va_end(args); + } + dev_printk(level, &sdev->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); +} +EXPORT_SYMBOL(sdev_prefix_printk); + +void scmd_printk(const char *level, const struct scsi_cmnd *scmd, + const char *fmt, ...) +{ + va_list args; + char *logbuf; + size_t off = 0, logbuf_len; + + if (!scmd || !scmd->cmnd) + return; + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd), + scmd->request->tag); + if (off < logbuf_len) { + va_start(args, fmt); + off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); + va_end(args); + } + dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); +} +EXPORT_SYMBOL(scmd_printk); + +static size_t scsi_format_opcode_name(char *buffer, size_t buf_len, + const unsigned char *cdbp) +{ + int sa, cdb0; + const char *cdb_name = NULL, *sa_name = NULL; + size_t off; + + cdb0 = cdbp[0]; + if (cdb0 == VARIABLE_LENGTH_CMD) { + int len = scsi_varlen_cdb_length(cdbp); + + if (len < 10) { + off = scnprintf(buffer, buf_len, + "short variable length command, len=%d", + len); + return off; + } + sa = (cdbp[8] << 8) + cdbp[9]; + } else + sa = cdbp[1] & 0x1f; + + if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) { + if (cdb_name) + off = scnprintf(buffer, buf_len, "%s", cdb_name); + else { + off = scnprintf(buffer, buf_len, "opcode=0x%x", cdb0); + if (WARN_ON(off >= buf_len)) + return off; + if (cdb0 >= VENDOR_SPECIFIC_CDB) + off += scnprintf(buffer + off, buf_len - off, + " (vendor)"); + else if (cdb0 >= 0x60 && cdb0 < 0x7e) + off += scnprintf(buffer + off, buf_len - off, + " (reserved)"); + } + } else { + if (sa_name) + off = scnprintf(buffer, buf_len, "%s", sa_name); + else if (cdb_name) + off = scnprintf(buffer, buf_len, "%s, sa=0x%x", + cdb_name, sa); + else + off = scnprintf(buffer, buf_len, + "opcode=0x%x, sa=0x%x", cdb0, sa); + } + WARN_ON(off >= buf_len); + return off; +} + +size_t __scsi_format_command(char *logbuf, size_t logbuf_len, + const unsigned char *cdb, size_t cdb_len) +{ + int len, k; + size_t off; + + off = scsi_format_opcode_name(logbuf, logbuf_len, cdb); + if (off >= logbuf_len) + return off; + len = scsi_command_size(cdb); + if (cdb_len < len) + len = cdb_len; + /* print out all bytes in cdb */ + for (k = 0; k < len; ++k) { + if (off > logbuf_len - 3) + break; + off += scnprintf(logbuf + off, logbuf_len - off, + " %02x", cdb[k]); + } + return off; +} +EXPORT_SYMBOL(__scsi_format_command); + +void scsi_print_command(struct scsi_cmnd *cmd) +{ + int k; + char *logbuf; + size_t off, logbuf_len; + + if (!cmd->cmnd) + return; + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + + off = sdev_format_header(logbuf, logbuf_len, + scmd_name(cmd), cmd->request->tag); + if (off >= logbuf_len) + goto out_printk; + off += scnprintf(logbuf + off, logbuf_len - off, "CDB: "); + if (WARN_ON(off >= logbuf_len)) + goto out_printk; + + off += scsi_format_opcode_name(logbuf + off, logbuf_len - off, + cmd->cmnd); + if (off >= logbuf_len) + goto out_printk; + + /* print out all bytes in cdb */ + if (cmd->cmd_len > 16) { + /* Print opcode in one line and use separate lines for CDB */ + off += scnprintf(logbuf + off, logbuf_len - off, "\n"); + dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); + for (k = 0; k < cmd->cmd_len; k += 16) { + size_t linelen = min(cmd->cmd_len - k, 16); + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + break; + off = sdev_format_header(logbuf, logbuf_len, + scmd_name(cmd), + cmd->request->tag); + if (!WARN_ON(off > logbuf_len - 58)) { + off += scnprintf(logbuf + off, logbuf_len - off, + "CDB[%02x]: ", k); + hex_dump_to_buffer(&cmd->cmnd[k], linelen, + 16, 1, logbuf + off, + logbuf_len - off, false); + } + dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", + logbuf); + scsi_log_release_buffer(logbuf); + } + return; + } + if (!WARN_ON(off > logbuf_len - 49)) { + off += scnprintf(logbuf + off, logbuf_len - off, " "); + hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1, + logbuf + off, logbuf_len - off, + false); + } +out_printk: + dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); +} +EXPORT_SYMBOL(scsi_print_command); + +static size_t +scsi_format_extd_sense(char *buffer, size_t buf_len, + unsigned char asc, unsigned char ascq) +{ + size_t off = 0; + const char *extd_sense_fmt = NULL; + const char *extd_sense_str = scsi_extd_sense_format(asc, ascq, + &extd_sense_fmt); + + if (extd_sense_str) { + off = scnprintf(buffer, buf_len, "Add. Sense: %s", + extd_sense_str); + if (extd_sense_fmt) + off += scnprintf(buffer + off, buf_len - off, + "(%s%x)", extd_sense_fmt, ascq); + } else { + if (asc >= 0x80) + off = scnprintf(buffer, buf_len, "<<vendor>>"); + off += scnprintf(buffer + off, buf_len - off, + "ASC=0x%x ", asc); + if (ascq >= 0x80) + off += scnprintf(buffer + off, buf_len - off, + "<<vendor>>"); + off += scnprintf(buffer + off, buf_len - off, + "ASCQ=0x%x ", ascq); + } + return off; +} + +static size_t +scsi_format_sense_hdr(char *buffer, size_t buf_len, + const struct scsi_sense_hdr *sshdr) +{ + const char *sense_txt; + size_t off; + + off = scnprintf(buffer, buf_len, "Sense Key : "); + sense_txt = scsi_sense_key_string(sshdr->sense_key); + if (sense_txt) + off += scnprintf(buffer + off, buf_len - off, + "%s ", sense_txt); + else + off += scnprintf(buffer + off, buf_len - off, + "0x%x ", sshdr->sense_key); + off += scnprintf(buffer + off, buf_len - off, + scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] "); + + if (sshdr->response_code >= 0x72) + off += scnprintf(buffer + off, buf_len - off, "[descriptor] "); + return off; +} + +static void +scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag, + const unsigned char *sense_buffer, int sense_len) +{ + char *logbuf; + size_t logbuf_len; + int i; + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + + for (i = 0; i < sense_len; i += 16) { + int len = min(sense_len - i, 16); + size_t off; + + off = sdev_format_header(logbuf, logbuf_len, + name, tag); + hex_dump_to_buffer(&sense_buffer[i], len, 16, 1, + logbuf + off, logbuf_len - off, + false); + dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); + } + scsi_log_release_buffer(logbuf); +} + +static void +scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name, + int tag, const struct scsi_sense_hdr *sshdr) +{ + char *logbuf; + size_t off, logbuf_len; + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + off = sdev_format_header(logbuf, logbuf_len, name, tag); + off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr); + dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + off = sdev_format_header(logbuf, logbuf_len, name, tag); + off += scsi_format_extd_sense(logbuf + off, logbuf_len - off, + sshdr->asc, sshdr->ascq); + dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); +} + +static void +scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag, + const unsigned char *sense_buffer, int sense_len) +{ + struct scsi_sense_hdr sshdr; + + if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) + scsi_log_print_sense_hdr(sdev, name, tag, &sshdr); + else + scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len); +} + +/* + * Print normalized SCSI sense header with a prefix. + */ +void +scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name, + const struct scsi_sense_hdr *sshdr) +{ + scsi_log_print_sense_hdr(sdev, name, -1, sshdr); +} +EXPORT_SYMBOL(scsi_print_sense_hdr); + +/* Normalize and print sense buffer with name prefix */ +void __scsi_print_sense(const struct scsi_device *sdev, const char *name, + const unsigned char *sense_buffer, int sense_len) +{ + scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len); +} +EXPORT_SYMBOL(__scsi_print_sense); + +/* Normalize and print sense buffer in SCSI command */ +void scsi_print_sense(const struct scsi_cmnd *cmd) +{ + scsi_log_print_sense(cmd->device, scmd_name(cmd), cmd->request->tag, + cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE); +} +EXPORT_SYMBOL(scsi_print_sense); + +void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg, + int disposition) +{ + char *logbuf; + size_t off, logbuf_len; + const char *mlret_string = scsi_mlreturn_string(disposition); + const char *hb_string = scsi_hostbyte_string(cmd->result); + const char *db_string = scsi_driverbyte_string(cmd->result); + + logbuf = scsi_log_reserve_buffer(&logbuf_len); + if (!logbuf) + return; + + off = sdev_format_header(logbuf, logbuf_len, + scmd_name(cmd), cmd->request->tag); + + if (off >= logbuf_len) + goto out_printk; + + if (msg) { + off += scnprintf(logbuf + off, logbuf_len - off, + "%s: ", msg); + if (WARN_ON(off >= logbuf_len)) + goto out_printk; + } + if (mlret_string) + off += scnprintf(logbuf + off, logbuf_len - off, + "%s ", mlret_string); + else + off += scnprintf(logbuf + off, logbuf_len - off, + "UNKNOWN(0x%02x) ", disposition); + if (WARN_ON(off >= logbuf_len)) + goto out_printk; + + off += scnprintf(logbuf + off, logbuf_len - off, "Result: "); + if (WARN_ON(off >= logbuf_len)) + goto out_printk; + + if (hb_string) + off += scnprintf(logbuf + off, logbuf_len - off, + "hostbyte=%s ", hb_string); + else + off += scnprintf(logbuf + off, logbuf_len - off, + "hostbyte=0x%02x ", host_byte(cmd->result)); + if (WARN_ON(off >= logbuf_len)) + goto out_printk; + + if (db_string) + off += scnprintf(logbuf + off, logbuf_len - off, + "driverbyte=%s", db_string); + else + off += scnprintf(logbuf + off, logbuf_len - off, + "driverbyte=0x%02x", driver_byte(cmd->result)); +out_printk: + dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); + scsi_log_release_buffer(logbuf); +} +EXPORT_SYMBOL(scsi_print_result); |