drivers/scsi/scsi_logging.c

   1 // SPDX-License-Identifier: GPL-2.0
   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);