Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 1 | /* |
| 2 | * scsi_logging.c |
| 3 | * |
| 4 | * Copyright (C) 2014 SUSE Linux Products GmbH |
| 5 | * Copyright (C) 2014 Hannes Reinecke <hare@suse.de> |
| 6 | * |
| 7 | * This file is released under the GPLv2 |
| 8 | */ |
| 9 | |
| 10 | #include <linux/kernel.h> |
| 11 | #include <linux/atomic.h> |
| 12 | |
| 13 | #include <scsi/scsi.h> |
| 14 | #include <scsi/scsi_cmnd.h> |
| 15 | #include <scsi/scsi_device.h> |
Hannes Reinecke | 9e5ed2a | 2015-01-08 07:43:44 +0100 | [diff] [blame^] | 16 | #include <scsi/scsi_eh.h> |
Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 17 | #include <scsi/scsi_dbg.h> |
| 18 | |
| 19 | #define SCSI_LOG_SPOOLSIZE 4096 |
Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 20 | |
| 21 | #if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG |
| 22 | #warning SCSI logging bitmask too large |
| 23 | #endif |
| 24 | |
| 25 | struct scsi_log_buf { |
| 26 | char buffer[SCSI_LOG_SPOOLSIZE]; |
| 27 | unsigned long map; |
| 28 | }; |
| 29 | |
| 30 | static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log); |
| 31 | |
| 32 | static char *scsi_log_reserve_buffer(size_t *len) |
| 33 | { |
| 34 | struct scsi_log_buf *buf; |
| 35 | unsigned long map_bits = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE; |
| 36 | unsigned long idx = 0; |
| 37 | |
| 38 | preempt_disable(); |
| 39 | buf = this_cpu_ptr(&scsi_format_log); |
| 40 | idx = find_first_zero_bit(&buf->map, map_bits); |
| 41 | if (likely(idx < map_bits)) { |
| 42 | while (test_and_set_bit(idx, &buf->map)) { |
| 43 | idx = find_next_zero_bit(&buf->map, map_bits, idx); |
| 44 | if (idx >= map_bits) |
| 45 | break; |
| 46 | } |
| 47 | } |
| 48 | if (WARN_ON(idx >= map_bits)) { |
| 49 | preempt_enable(); |
| 50 | return NULL; |
| 51 | } |
| 52 | *len = SCSI_LOG_BUFSIZE; |
| 53 | return buf->buffer + idx * SCSI_LOG_BUFSIZE; |
| 54 | } |
| 55 | |
| 56 | static void scsi_log_release_buffer(char *bufptr) |
| 57 | { |
| 58 | struct scsi_log_buf *buf; |
| 59 | unsigned long idx; |
| 60 | int ret; |
| 61 | |
| 62 | buf = this_cpu_ptr(&scsi_format_log); |
| 63 | if (bufptr >= buf->buffer && |
| 64 | bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) { |
| 65 | idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE; |
| 66 | ret = test_and_clear_bit(idx, &buf->map); |
| 67 | WARN_ON(!ret); |
| 68 | } |
| 69 | preempt_enable(); |
| 70 | } |
| 71 | |
Hannes Reinecke | 9e5ed2a | 2015-01-08 07:43:44 +0100 | [diff] [blame^] | 72 | static size_t scmd_format_header(char *logbuf, size_t logbuf_len, |
| 73 | struct gendisk *disk, int tag) |
| 74 | { |
| 75 | size_t off = 0; |
| 76 | |
| 77 | if (disk) |
| 78 | off += scnprintf(logbuf + off, logbuf_len - off, |
| 79 | "[%s] ", disk->disk_name); |
| 80 | |
| 81 | if (WARN_ON(off >= logbuf_len)) |
| 82 | return off; |
| 83 | |
| 84 | if (tag >= 0) |
| 85 | off += scnprintf(logbuf + off, logbuf_len - off, |
| 86 | "tag#%d ", tag); |
| 87 | return off; |
| 88 | } |
| 89 | |
Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 90 | int sdev_prefix_printk(const char *level, const struct scsi_device *sdev, |
| 91 | const char *name, const char *fmt, ...) |
| 92 | { |
| 93 | va_list args; |
| 94 | char *logbuf; |
| 95 | size_t off = 0, logbuf_len; |
| 96 | int ret; |
| 97 | |
| 98 | if (!sdev) |
| 99 | return 0; |
| 100 | |
| 101 | logbuf = scsi_log_reserve_buffer(&logbuf_len); |
| 102 | if (!logbuf) |
| 103 | return 0; |
| 104 | |
| 105 | if (name) |
| 106 | off += scnprintf(logbuf + off, logbuf_len - off, |
| 107 | "[%s] ", name); |
Hannes Reinecke | 9e5ed2a | 2015-01-08 07:43:44 +0100 | [diff] [blame^] | 108 | if (!WARN_ON(off >= logbuf_len)) { |
| 109 | va_start(args, fmt); |
| 110 | off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); |
| 111 | va_end(args); |
| 112 | } |
Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 113 | ret = dev_printk(level, &sdev->sdev_gendev, "%s", logbuf); |
| 114 | scsi_log_release_buffer(logbuf); |
| 115 | return ret; |
| 116 | } |
| 117 | EXPORT_SYMBOL(sdev_prefix_printk); |
| 118 | |
| 119 | int scmd_printk(const char *level, const struct scsi_cmnd *scmd, |
| 120 | const char *fmt, ...) |
| 121 | { |
| 122 | struct gendisk *disk = scmd->request->rq_disk; |
| 123 | va_list args; |
| 124 | char *logbuf; |
| 125 | size_t off = 0, logbuf_len; |
| 126 | int ret; |
| 127 | |
| 128 | if (!scmd || !scmd->cmnd) |
| 129 | return 0; |
| 130 | |
| 131 | logbuf = scsi_log_reserve_buffer(&logbuf_len); |
| 132 | if (!logbuf) |
| 133 | return 0; |
Hannes Reinecke | 9e5ed2a | 2015-01-08 07:43:44 +0100 | [diff] [blame^] | 134 | off = scmd_format_header(logbuf, logbuf_len, disk, |
| 135 | scmd->request->tag); |
| 136 | if (off < logbuf_len) { |
| 137 | va_start(args, fmt); |
| 138 | off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); |
| 139 | va_end(args); |
| 140 | } |
Hannes Reinecke | ded85c1 | 2015-01-08 07:43:42 +0100 | [diff] [blame] | 141 | ret = dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf); |
| 142 | scsi_log_release_buffer(logbuf); |
| 143 | return ret; |
| 144 | } |
| 145 | EXPORT_SYMBOL(scmd_printk); |
Hannes Reinecke | 9e5ed2a | 2015-01-08 07:43:44 +0100 | [diff] [blame^] | 146 | |
| 147 | static size_t scsi_format_opcode_name(char *buffer, size_t buf_len, |
| 148 | const unsigned char *cdbp) |
| 149 | { |
| 150 | int sa, cdb0; |
| 151 | const char *cdb_name = NULL, *sa_name = NULL; |
| 152 | size_t off; |
| 153 | |
| 154 | cdb0 = cdbp[0]; |
| 155 | if (cdb0 == VARIABLE_LENGTH_CMD) { |
| 156 | int len = scsi_varlen_cdb_length(cdbp); |
| 157 | |
| 158 | if (len < 10) { |
| 159 | off = scnprintf(buffer, buf_len, |
| 160 | "short variable length command, len=%d", |
| 161 | len); |
| 162 | return off; |
| 163 | } |
| 164 | sa = (cdbp[8] << 8) + cdbp[9]; |
| 165 | } else |
| 166 | sa = cdbp[1] & 0x1f; |
| 167 | |
| 168 | if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) { |
| 169 | if (cdb_name) |
| 170 | off = scnprintf(buffer, buf_len, "%s", cdb_name); |
| 171 | else { |
| 172 | off = scnprintf(buffer, buf_len, "opcode=0x%x", cdb0); |
| 173 | if (WARN_ON(off >= buf_len)) |
| 174 | return off; |
| 175 | if (cdb0 >= VENDOR_SPECIFIC_CDB) |
| 176 | off += scnprintf(buffer + off, buf_len - off, |
| 177 | " (vendor)"); |
| 178 | else if (cdb0 >= 0x60 && cdb0 < 0x7e) |
| 179 | off += scnprintf(buffer + off, buf_len - off, |
| 180 | " (reserved)"); |
| 181 | } |
| 182 | } else { |
| 183 | if (sa_name) |
| 184 | off = scnprintf(buffer, buf_len, "%s", sa_name); |
| 185 | else if (cdb_name) |
| 186 | off = scnprintf(buffer, buf_len, "%s, sa=0x%x", |
| 187 | cdb_name, sa); |
| 188 | else |
| 189 | off = scnprintf(buffer, buf_len, |
| 190 | "opcode=0x%x, sa=0x%x", cdb0, sa); |
| 191 | } |
| 192 | WARN_ON(off >= buf_len); |
| 193 | return off; |
| 194 | } |
| 195 | |
| 196 | size_t __scsi_format_command(char *logbuf, size_t logbuf_len, |
| 197 | const unsigned char *cdb, size_t cdb_len) |
| 198 | { |
| 199 | int len, k; |
| 200 | size_t off; |
| 201 | |
| 202 | off = scsi_format_opcode_name(logbuf, logbuf_len, cdb); |
| 203 | if (off >= logbuf_len) |
| 204 | return off; |
| 205 | len = scsi_command_size(cdb); |
| 206 | if (cdb_len < len) |
| 207 | len = cdb_len; |
| 208 | /* print out all bytes in cdb */ |
| 209 | for (k = 0; k < len; ++k) { |
| 210 | if (off > logbuf_len - 3) |
| 211 | break; |
| 212 | off += scnprintf(logbuf + off, logbuf_len - off, |
| 213 | " %02x", cdb[k]); |
| 214 | } |
| 215 | return off; |
| 216 | } |
| 217 | EXPORT_SYMBOL(__scsi_format_command); |
| 218 | |
| 219 | void scsi_print_command(struct scsi_cmnd *cmd) |
| 220 | { |
| 221 | struct gendisk *disk = cmd->request->rq_disk; |
| 222 | int k; |
| 223 | char *logbuf; |
| 224 | size_t off, logbuf_len; |
| 225 | |
| 226 | if (!cmd->cmnd) |
| 227 | return; |
| 228 | |
| 229 | logbuf = scsi_log_reserve_buffer(&logbuf_len); |
| 230 | if (!logbuf) |
| 231 | return; |
| 232 | |
| 233 | off = scmd_format_header(logbuf, logbuf_len, disk, cmd->request->tag); |
| 234 | if (off >= logbuf_len) |
| 235 | goto out_printk; |
| 236 | off += scnprintf(logbuf + off, logbuf_len - off, "CDB: "); |
| 237 | if (WARN_ON(off >= logbuf_len)) |
| 238 | goto out_printk; |
| 239 | |
| 240 | off += scsi_format_opcode_name(logbuf + off, logbuf_len - off, |
| 241 | cmd->cmnd); |
| 242 | if (off >= logbuf_len) |
| 243 | goto out_printk; |
| 244 | |
| 245 | /* print out all bytes in cdb */ |
| 246 | if (cmd->cmd_len > 16) { |
| 247 | /* Print opcode in one line and use separate lines for CDB */ |
| 248 | off += scnprintf(logbuf + off, logbuf_len - off, "\n"); |
| 249 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf); |
| 250 | scsi_log_release_buffer(logbuf); |
| 251 | for (k = 0; k < cmd->cmd_len; k += 16) { |
| 252 | size_t linelen = min(cmd->cmd_len - k, 16); |
| 253 | |
| 254 | logbuf = scsi_log_reserve_buffer(&logbuf_len); |
| 255 | if (!logbuf) |
| 256 | break; |
| 257 | off = scmd_format_header(logbuf, logbuf_len, disk, |
| 258 | cmd->request->tag); |
| 259 | if (!WARN_ON(off > logbuf_len - 58)) { |
| 260 | off += scnprintf(logbuf + off, logbuf_len - off, |
| 261 | "CDB[%02x]: ", k); |
| 262 | hex_dump_to_buffer(&cmd->cmnd[k], linelen, |
| 263 | 16, 1, logbuf + off, |
| 264 | logbuf_len - off, false); |
| 265 | } |
| 266 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, |
| 267 | logbuf); |
| 268 | scsi_log_release_buffer(logbuf); |
| 269 | } |
| 270 | return; |
| 271 | } |
| 272 | if (!WARN_ON(off > logbuf_len - 49)) { |
| 273 | off += scnprintf(logbuf + off, logbuf_len - off, " "); |
| 274 | hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1, |
| 275 | logbuf + off, logbuf_len - off, |
| 276 | false); |
| 277 | } |
| 278 | out_printk: |
| 279 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, logbuf); |
| 280 | scsi_log_release_buffer(logbuf); |
| 281 | } |
| 282 | EXPORT_SYMBOL(scsi_print_command); |