1 // SPDX-License-Identifier: GPL-2.0-only 2 /* 3 * scsi_logging.c 4 * 5 * Copyright (C) 2014 SUSE Linux Products GmbH 6 * Copyright (C) 2014 Hannes Reinecke <hare@suse.de> 7 */ 8 9 #include <linux/kernel.h> 10 #include <linux/atomic.h> 11 12 #include <scsi/scsi.h> 13 #include <scsi/scsi_cmnd.h> 14 #include <scsi/scsi_device.h> 15 #include <scsi/scsi_eh.h> 16 #include <scsi/scsi_dbg.h> 17 18 #define SCSI_LOG_SPOOLSIZE 4096 19 20 #if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG 21 #warning SCSI logging bitmask too large 22 #endif 23 24 struct scsi_log_buf { 25 char buffer[SCSI_LOG_SPOOLSIZE]; 26 unsigned long map; 27 }; 28 29 static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log); 30 31 static char *scsi_log_reserve_buffer(size_t *len) 32 { 33 struct scsi_log_buf *buf; 34 unsigned long map_bits = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE; 35 unsigned long idx = 0; 36 37 preempt_disable(); 38 buf = this_cpu_ptr(&scsi_format_log); 39 idx = find_first_zero_bit(&buf->map, map_bits); 40 if (likely(idx < map_bits)) { 41 while (test_and_set_bit(idx, &buf->map)) { 42 idx = find_next_zero_bit(&buf->map, map_bits, idx); 43 if (idx >= map_bits) 44 break; 45 } 46 } 47 if (WARN_ON(idx >= map_bits)) { 48 preempt_enable(); 49 return NULL; 50 } 51 *len = SCSI_LOG_BUFSIZE; 52 return buf->buffer + idx * SCSI_LOG_BUFSIZE; 53 } 54 55 static void scsi_log_release_buffer(char *bufptr) 56 { 57 struct scsi_log_buf *buf; 58 unsigned long idx; 59 int ret; 60 61 buf = this_cpu_ptr(&scsi_format_log); 62 if (bufptr >= buf->buffer && 63 bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) { 64 idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE; 65 ret = test_and_clear_bit(idx, &buf->map); 66 WARN_ON(!ret); 67 } 68 preempt_enable(); 69 } 70 71 static inline const char *scmd_name(const struct scsi_cmnd *scmd) 72 { 73 return scmd->request->rq_disk ? 74 scmd->request->rq_disk->disk_name : NULL; 75 } 76 77 static size_t sdev_format_header(char *logbuf, size_t logbuf_len, 78 const char *name, int tag) 79 { 80 size_t off = 0; 81 82 if (name) 83 off += scnprintf(logbuf + off, logbuf_len - off, 84 "[%s] ", name); 85 86 if (WARN_ON(off >= logbuf_len)) 87 return off; 88 89 if (tag >= 0) 90 off += scnprintf(logbuf + off, logbuf_len - off, 91 "tag#%d ", tag); 92 return off; 93 } 94 95 void sdev_prefix_printk(const char *level, const struct scsi_device *sdev, 96 const char *name, const char *fmt, ...) 97 { 98 va_list args; 99 char *logbuf; 100 size_t off = 0, logbuf_len; 101 102 if (!sdev) 103 return; 104 105 logbuf = scsi_log_reserve_buffer(&logbuf_len); 106 if (!logbuf) 107 return; 108 109 if (name) 110 off += scnprintf(logbuf + off, logbuf_len - off, 111 "[%s] ", name); 112 if (!WARN_ON(off >= logbuf_len)) { 113 va_start(args, fmt); 114 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); 115 va_end(args); 116 } 117 dev_printk(level, &sdev->sdev_gendev, "%s", logbuf); 118 scsi_log_release_buffer(logbuf); 119 } 120 EXPORT_SYMBOL(sdev_prefix_printk); 121 122 void scmd_printk(const char *level, const struct scsi_cmnd *scmd, 123 const char *fmt, ...) 124 { 125 va_list args; 126 char *logbuf; 127 size_t off = 0, logbuf_len; 128 129 if (!scmd || !scmd->cmnd) 130 return; 131 132 logbuf = scsi_log_reserve_buffer(&logbuf_len); 133 if (!logbuf) 134 return; 135 off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd), 136 scmd->request->tag); 137 if (off < logbuf_len) { 138 va_start(args, fmt); 139 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); 140 va_end(args); 141 } 142 dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf); 143 scsi_log_release_buffer(logbuf); 144 } 145 EXPORT_SYMBOL(scmd_printk); 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 int k; 222 char *logbuf; 223 size_t off, logbuf_len; 224 225 if (!cmd->cmnd) 226 return; 227 228 logbuf = scsi_log_reserve_buffer(&logbuf_len); 229 if (!logbuf) 230 return; 231 232 off = sdev_format_header(logbuf, logbuf_len, 233 scmd_name(cmd), 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, "%s", 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 = sdev_format_header(logbuf, logbuf_len, 258 scmd_name(cmd), 259 cmd->request->tag); 260 if (!WARN_ON(off > logbuf_len - 58)) { 261 off += scnprintf(logbuf + off, logbuf_len - off, 262 "CDB[%02x]: ", k); 263 hex_dump_to_buffer(&cmd->cmnd[k], linelen, 264 16, 1, logbuf + off, 265 logbuf_len - off, false); 266 } 267 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", 268 logbuf); 269 scsi_log_release_buffer(logbuf); 270 } 271 return; 272 } 273 if (!WARN_ON(off > logbuf_len - 49)) { 274 off += scnprintf(logbuf + off, logbuf_len - off, " "); 275 hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1, 276 logbuf + off, logbuf_len - off, 277 false); 278 } 279 out_printk: 280 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); 281 scsi_log_release_buffer(logbuf); 282 } 283 EXPORT_SYMBOL(scsi_print_command); 284 285 static size_t 286 scsi_format_extd_sense(char *buffer, size_t buf_len, 287 unsigned char asc, unsigned char ascq) 288 { 289 size_t off = 0; 290 const char *extd_sense_fmt = NULL; 291 const char *extd_sense_str = scsi_extd_sense_format(asc, ascq, 292 &extd_sense_fmt); 293 294 if (extd_sense_str) { 295 off = scnprintf(buffer, buf_len, "Add. Sense: %s", 296 extd_sense_str); 297 if (extd_sense_fmt) 298 off += scnprintf(buffer + off, buf_len - off, 299 "(%s%x)", extd_sense_fmt, ascq); 300 } else { 301 if (asc >= 0x80) 302 off = scnprintf(buffer, buf_len, "<<vendor>>"); 303 off += scnprintf(buffer + off, buf_len - off, 304 "ASC=0x%x ", asc); 305 if (ascq >= 0x80) 306 off += scnprintf(buffer + off, buf_len - off, 307 "<<vendor>>"); 308 off += scnprintf(buffer + off, buf_len - off, 309 "ASCQ=0x%x ", ascq); 310 } 311 return off; 312 } 313 314 static size_t 315 scsi_format_sense_hdr(char *buffer, size_t buf_len, 316 const struct scsi_sense_hdr *sshdr) 317 { 318 const char *sense_txt; 319 size_t off; 320 321 off = scnprintf(buffer, buf_len, "Sense Key : "); 322 sense_txt = scsi_sense_key_string(sshdr->sense_key); 323 if (sense_txt) 324 off += scnprintf(buffer + off, buf_len - off, 325 "%s ", sense_txt); 326 else 327 off += scnprintf(buffer + off, buf_len - off, 328 "0x%x ", sshdr->sense_key); 329 off += scnprintf(buffer + off, buf_len - off, 330 scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] "); 331 332 if (sshdr->response_code >= 0x72) 333 off += scnprintf(buffer + off, buf_len - off, "[descriptor] "); 334 return off; 335 } 336 337 static void 338 scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag, 339 const unsigned char *sense_buffer, int sense_len) 340 { 341 char *logbuf; 342 size_t logbuf_len; 343 int i; 344 345 logbuf = scsi_log_reserve_buffer(&logbuf_len); 346 if (!logbuf) 347 return; 348 349 for (i = 0; i < sense_len; i += 16) { 350 int len = min(sense_len - i, 16); 351 size_t off; 352 353 off = sdev_format_header(logbuf, logbuf_len, 354 name, tag); 355 hex_dump_to_buffer(&sense_buffer[i], len, 16, 1, 356 logbuf + off, logbuf_len - off, 357 false); 358 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); 359 } 360 scsi_log_release_buffer(logbuf); 361 } 362 363 static void 364 scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name, 365 int tag, const struct scsi_sense_hdr *sshdr) 366 { 367 char *logbuf; 368 size_t off, logbuf_len; 369 370 logbuf = scsi_log_reserve_buffer(&logbuf_len); 371 if (!logbuf) 372 return; 373 off = sdev_format_header(logbuf, logbuf_len, name, tag); 374 off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr); 375 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); 376 scsi_log_release_buffer(logbuf); 377 378 logbuf = scsi_log_reserve_buffer(&logbuf_len); 379 if (!logbuf) 380 return; 381 off = sdev_format_header(logbuf, logbuf_len, name, tag); 382 off += scsi_format_extd_sense(logbuf + off, logbuf_len - off, 383 sshdr->asc, sshdr->ascq); 384 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); 385 scsi_log_release_buffer(logbuf); 386 } 387 388 static void 389 scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag, 390 const unsigned char *sense_buffer, int sense_len) 391 { 392 struct scsi_sense_hdr sshdr; 393 394 if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) 395 scsi_log_print_sense_hdr(sdev, name, tag, &sshdr); 396 else 397 scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len); 398 } 399 400 /* 401 * Print normalized SCSI sense header with a prefix. 402 */ 403 void 404 scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name, 405 const struct scsi_sense_hdr *sshdr) 406 { 407 scsi_log_print_sense_hdr(sdev, name, -1, sshdr); 408 } 409 EXPORT_SYMBOL(scsi_print_sense_hdr); 410 411 /* Normalize and print sense buffer with name prefix */ 412 void __scsi_print_sense(const struct scsi_device *sdev, const char *name, 413 const unsigned char *sense_buffer, int sense_len) 414 { 415 scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len); 416 } 417 EXPORT_SYMBOL(__scsi_print_sense); 418 419 /* Normalize and print sense buffer in SCSI command */ 420 void scsi_print_sense(const struct scsi_cmnd *cmd) 421 { 422 scsi_log_print_sense(cmd->device, scmd_name(cmd), cmd->request->tag, 423 cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE); 424 } 425 EXPORT_SYMBOL(scsi_print_sense); 426 427 void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg, 428 int disposition) 429 { 430 char *logbuf; 431 size_t off, logbuf_len; 432 const char *mlret_string = scsi_mlreturn_string(disposition); 433 const char *hb_string = scsi_hostbyte_string(cmd->result); 434 const char *db_string = scsi_driverbyte_string(cmd->result); 435 436 logbuf = scsi_log_reserve_buffer(&logbuf_len); 437 if (!logbuf) 438 return; 439 440 off = sdev_format_header(logbuf, logbuf_len, 441 scmd_name(cmd), cmd->request->tag); 442 443 if (off >= logbuf_len) 444 goto out_printk; 445 446 if (msg) { 447 off += scnprintf(logbuf + off, logbuf_len - off, 448 "%s: ", msg); 449 if (WARN_ON(off >= logbuf_len)) 450 goto out_printk; 451 } 452 if (mlret_string) 453 off += scnprintf(logbuf + off, logbuf_len - off, 454 "%s ", mlret_string); 455 else 456 off += scnprintf(logbuf + off, logbuf_len - off, 457 "UNKNOWN(0x%02x) ", disposition); 458 if (WARN_ON(off >= logbuf_len)) 459 goto out_printk; 460 461 off += scnprintf(logbuf + off, logbuf_len - off, "Result: "); 462 if (WARN_ON(off >= logbuf_len)) 463 goto out_printk; 464 465 if (hb_string) 466 off += scnprintf(logbuf + off, logbuf_len - off, 467 "hostbyte=%s ", hb_string); 468 else 469 off += scnprintf(logbuf + off, logbuf_len - off, 470 "hostbyte=0x%02x ", host_byte(cmd->result)); 471 if (WARN_ON(off >= logbuf_len)) 472 goto out_printk; 473 474 if (db_string) 475 off += scnprintf(logbuf + off, logbuf_len - off, 476 "driverbyte=%s", db_string); 477 else 478 off += scnprintf(logbuf + off, logbuf_len - off, 479 "driverbyte=0x%02x", driver_byte(cmd->result)); 480 out_printk: 481 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); 482 scsi_log_release_buffer(logbuf); 483 } 484 EXPORT_SYMBOL(scsi_print_result); 485