drivers/scsi/scsi_logging.c

   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 <[email protected]>
   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 static char *scsi_log_reserve_buffer(size_t *len)
  19 {
  20         *len = 128;
  21         return kmalloc(*len, GFP_ATOMIC);
  22 }
  23
  24 static void scsi_log_release_buffer(char *bufptr)
  25 {
  26         kfree(bufptr);
  27 }
  28
  29 static inline const char *scmd_name(const struct scsi_cmnd *scmd)
  30 {
  31         return scmd->request->rq_disk ?
  32                 scmd->request->rq_disk->disk_name : NULL;
  33 }
  34
  35 static size_t sdev_format_header(char *logbuf, size_t logbuf_len,
  36                                  const char *name, int tag)
  37 {
  38         size_t off = 0;
  39
  40         if (name)
  41                 off += scnprintf(logbuf + off, logbuf_len - off,
  42                                  "[%s] ", name);
  43
  44         if (WARN_ON(off >= logbuf_len))
  45                 return off;
  46
  47         if (tag >= 0)
  48                 off += scnprintf(logbuf + off, logbuf_len - off,
  49                                  "tag#%d ", tag);
  50         return off;
  51 }
  52
  53 void sdev_prefix_printk(const char *level, const struct scsi_device *sdev,
  54                         const char *name, const char *fmt, ...)
  55 {
  56         va_list args;
  57         char *logbuf;
  58         size_t off = 0, logbuf_len;
  59
  60         if (!sdev)
  61                 return;
  62
  63         logbuf = scsi_log_reserve_buffer(&logbuf_len);
  64         if (!logbuf)
  65                 return;
  66
  67         if (name)
  68                 off += scnprintf(logbuf + off, logbuf_len - off,
  69                                  "[%s] ", name);
  70         if (!WARN_ON(off >= logbuf_len)) {
  71                 va_start(args, fmt);
  72                 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
  73                 va_end(args);
  74         }
  75         dev_printk(level, &sdev->sdev_gendev, "%s", logbuf);
  76         scsi_log_release_buffer(logbuf);
  77 }
  78 EXPORT_SYMBOL(sdev_prefix_printk);
  79
  80 void scmd_printk(const char *level, const struct scsi_cmnd *scmd,
  81                 const char *fmt, ...)
  82 {
  83         va_list args;
  84         char *logbuf;
  85         size_t off = 0, logbuf_len;
  86
  87         if (!scmd || !scmd->cmnd)
  88                 return;
  89
  90         logbuf = scsi_log_reserve_buffer(&logbuf_len);
  91         if (!logbuf)
  92                 return;
  93         off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd),
  94                                  scmd->request->tag);
  95         if (off < logbuf_len) {
  96                 va_start(args, fmt);
  97                 off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args);
  98                 va_end(args);
  99         }
 100         dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf);
 101         scsi_log_release_buffer(logbuf);
 102 }
 103 EXPORT_SYMBOL(scmd_printk);
 104
 105 static size_t scsi_format_opcode_name(char *buffer, size_t buf_len,
 106                                       const unsigned char *cdbp)
 107 {
 108         int sa, cdb0;
 109         const char *cdb_name = NULL, *sa_name = NULL;
 110         size_t off;
 111
 112         cdb0 = cdbp[0];
 113         if (cdb0 == VARIABLE_LENGTH_CMD) {
 114                 int len = scsi_varlen_cdb_length(cdbp);
 115
 116                 if (len < 10) {
 117                         off = scnprintf(buffer, buf_len,
 118                                         "short variable length command, len=%d",
 119                                         len);
 120                         return off;
 121                 }
 122                 sa = (cdbp[8] << 8) + cdbp[9];
 123         } else
 124                 sa = cdbp[1] & 0x1f;
 125
 126         if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) {
 127                 if (cdb_name)
 128                         off = scnprintf(buffer, buf_len, "%s", cdb_name);
 129                 else {
 130                         off = scnprintf(buffer, buf_len, "opcode=0x%x", cdb0);
 131                         if (WARN_ON(off >= buf_len))
 132                                 return off;
 133                         if (cdb0 >= VENDOR_SPECIFIC_CDB)
 134                                 off += scnprintf(buffer + off, buf_len - off,
 135                                                  " (vendor)");
 136                         else if (cdb0 >= 0x60 && cdb0 < 0x7e)
 137                                 off += scnprintf(buffer + off, buf_len - off,
 138                                                  " (reserved)");
 139                 }
 140         } else {
 141                 if (sa_name)
 142                         off = scnprintf(buffer, buf_len, "%s", sa_name);
 143                 else if (cdb_name)
 144                         off = scnprintf(buffer, buf_len, "%s, sa=0x%x",
 145                                         cdb_name, sa);
 146                 else
 147                         off = scnprintf(buffer, buf_len,
 148                                         "opcode=0x%x, sa=0x%x", cdb0, sa);
 149         }
 150         WARN_ON(off >= buf_len);
 151         return off;
 152 }
 153
 154 size_t __scsi_format_command(char *logbuf, size_t logbuf_len,
 155                              const unsigned char *cdb, size_t cdb_len)
 156 {
 157         int len, k;
 158         size_t off;
 159
 160         off = scsi_format_opcode_name(logbuf, logbuf_len, cdb);
 161         if (off >= logbuf_len)
 162                 return off;
 163         len = scsi_command_size(cdb);
 164         if (cdb_len < len)
 165                 len = cdb_len;
 166         /* print out all bytes in cdb */
 167         for (k = 0; k < len; ++k) {
 168                 if (off > logbuf_len - 3)
 169                         break;
 170                 off += scnprintf(logbuf + off, logbuf_len - off,
 171                                  " %02x", cdb[k]);
 172         }
 173         return off;
 174 }
 175 EXPORT_SYMBOL(__scsi_format_command);
 176
 177 void scsi_print_command(struct scsi_cmnd *cmd)
 178 {
 179         int k;
 180         char *logbuf;
 181         size_t off, logbuf_len;
 182
 183         if (!cmd->cmnd)
 184                 return;
 185
 186         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 187         if (!logbuf)
 188                 return;
 189
 190         off = sdev_format_header(logbuf, logbuf_len,
 191                                  scmd_name(cmd), cmd->request->tag);
 192         if (off >= logbuf_len)
 193                 goto out_printk;
 194         off += scnprintf(logbuf + off, logbuf_len - off, "CDB: ");
 195         if (WARN_ON(off >= logbuf_len))
 196                 goto out_printk;
 197
 198         off += scsi_format_opcode_name(logbuf + off, logbuf_len - off,
 199                                        cmd->cmnd);
 200         if (off >= logbuf_len)
 201                 goto out_printk;
 202
 203         /* print out all bytes in cdb */
 204         if (cmd->cmd_len > 16) {
 205                 /* Print opcode in one line and use separate lines for CDB */
 206                 off += scnprintf(logbuf + off, logbuf_len - off, "\n");
 207                 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
 208                 scsi_log_release_buffer(logbuf);
 209                 for (k = 0; k < cmd->cmd_len; k += 16) {
 210                         size_t linelen = min(cmd->cmd_len - k, 16);
 211
 212                         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 213                         if (!logbuf)
 214                                 break;
 215                         off = sdev_format_header(logbuf, logbuf_len,
 216                                                  scmd_name(cmd),
 217                                                  cmd->request->tag);
 218                         if (!WARN_ON(off > logbuf_len - 58)) {
 219                                 off += scnprintf(logbuf + off, logbuf_len - off,
 220                                                  "CDB[%02x]: ", k);
 221                                 hex_dump_to_buffer(&cmd->cmnd[k], linelen,
 222                                                    16, 1, logbuf + off,
 223                                                    logbuf_len - off, false);
 224                         }
 225                         dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s",
 226                                    logbuf);
 227                         scsi_log_release_buffer(logbuf);
 228                 }
 229                 return;
 230         }
 231         if (!WARN_ON(off > logbuf_len - 49)) {
 232                 off += scnprintf(logbuf + off, logbuf_len - off, " ");
 233                 hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,
 234                                    logbuf + off, logbuf_len - off,
 235                                    false);
 236         }
 237 out_printk:
 238         dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
 239         scsi_log_release_buffer(logbuf);
 240 }
 241 EXPORT_SYMBOL(scsi_print_command);
 242
 243 static size_t
 244 scsi_format_extd_sense(char *buffer, size_t buf_len,
 245                        unsigned char asc, unsigned char ascq)
 246 {
 247         size_t off = 0;
 248         const char *extd_sense_fmt = NULL;
 249         const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,
 250                                                             &extd_sense_fmt);
 251
 252         if (extd_sense_str) {
 253                 off = scnprintf(buffer, buf_len, "Add. Sense: %s",
 254                                 extd_sense_str);
 255                 if (extd_sense_fmt)
 256                         off += scnprintf(buffer + off, buf_len - off,
 257                                          "(%s%x)", extd_sense_fmt, ascq);
 258         } else {
 259                 if (asc >= 0x80)
 260                         off = scnprintf(buffer, buf_len, "<<vendor>>");
 261                 off += scnprintf(buffer + off, buf_len - off,
 262                                  "ASC=0x%x ", asc);
 263                 if (ascq >= 0x80)
 264                         off += scnprintf(buffer + off, buf_len - off,
 265                                          "<<vendor>>");
 266                 off += scnprintf(buffer + off, buf_len - off,
 267                                  "ASCQ=0x%x ", ascq);
 268         }
 269         return off;
 270 }
 271
 272 static size_t
 273 scsi_format_sense_hdr(char *buffer, size_t buf_len,
 274                       const struct scsi_sense_hdr *sshdr)
 275 {
 276         const char *sense_txt;
 277         size_t off;
 278
 279         off = scnprintf(buffer, buf_len, "Sense Key : ");
 280         sense_txt = scsi_sense_key_string(sshdr->sense_key);
 281         if (sense_txt)
 282                 off += scnprintf(buffer + off, buf_len - off,
 283                                  "%s ", sense_txt);
 284         else
 285                 off += scnprintf(buffer + off, buf_len - off,
 286                                  "0x%x ", sshdr->sense_key);
 287         off += scnprintf(buffer + off, buf_len - off,
 288                 scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] ");
 289
 290         if (sshdr->response_code >= 0x72)
 291                 off += scnprintf(buffer + off, buf_len - off, "[descriptor] ");
 292         return off;
 293 }
 294
 295 static void
 296 scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag,
 297                     const unsigned char *sense_buffer, int sense_len)
 298 {
 299         char *logbuf;
 300         size_t logbuf_len;
 301         int i;
 302
 303         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 304         if (!logbuf)
 305                 return;
 306
 307         for (i = 0; i < sense_len; i += 16) {
 308                 int len = min(sense_len - i, 16);
 309                 size_t off;
 310
 311                 off = sdev_format_header(logbuf, logbuf_len,
 312                                          name, tag);
 313                 hex_dump_to_buffer(&sense_buffer[i], len, 16, 1,
 314                                    logbuf + off, logbuf_len - off,
 315                                    false);
 316                 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
 317         }
 318         scsi_log_release_buffer(logbuf);
 319 }
 320
 321 static void
 322 scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name,
 323                          int tag, const struct scsi_sense_hdr *sshdr)
 324 {
 325         char *logbuf;
 326         size_t off, logbuf_len;
 327
 328         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 329         if (!logbuf)
 330                 return;
 331         off = sdev_format_header(logbuf, logbuf_len, name, tag);
 332         off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr);
 333         dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
 334         scsi_log_release_buffer(logbuf);
 335
 336         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 337         if (!logbuf)
 338                 return;
 339         off = sdev_format_header(logbuf, logbuf_len, name, tag);
 340         off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,
 341                                       sshdr->asc, sshdr->ascq);
 342         dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);
 343         scsi_log_release_buffer(logbuf);
 344 }
 345
 346 static void
 347 scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag,
 348                      const unsigned char *sense_buffer, int sense_len)
 349 {
 350         struct scsi_sense_hdr sshdr;
 351
 352         if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr))
 353                 scsi_log_print_sense_hdr(sdev, name, tag, &sshdr);
 354         else
 355                 scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len);
 356 }
 357
 358 /*
 359  * Print normalized SCSI sense header with a prefix.
 360  */
 361 void
 362 scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,
 363                      const struct scsi_sense_hdr *sshdr)
 364 {
 365         scsi_log_print_sense_hdr(sdev, name, -1, sshdr);
 366 }
 367 EXPORT_SYMBOL(scsi_print_sense_hdr);
 368
 369 /* Normalize and print sense buffer with name prefix */
 370 void __scsi_print_sense(const struct scsi_device *sdev, const char *name,
 371                         const unsigned char *sense_buffer, int sense_len)
 372 {
 373         scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len);
 374 }
 375 EXPORT_SYMBOL(__scsi_print_sense);
 376
 377 /* Normalize and print sense buffer in SCSI command */
 378 void scsi_print_sense(const struct scsi_cmnd *cmd)
 379 {
 380         scsi_log_print_sense(cmd->device, scmd_name(cmd), cmd->request->tag,
 381                              cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);
 382 }
 383 EXPORT_SYMBOL(scsi_print_sense);
 384
 385 void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg,
 386                        int disposition)
 387 {
 388         char *logbuf;
 389         size_t off, logbuf_len;
 390         const char *mlret_string = scsi_mlreturn_string(disposition);
 391         const char *hb_string = scsi_hostbyte_string(cmd->result);
 392         const char *db_string = scsi_driverbyte_string(cmd->result);
 393         unsigned long cmd_age = (jiffies - cmd->jiffies_at_alloc) / HZ;
 394
 395         logbuf = scsi_log_reserve_buffer(&logbuf_len);
 396         if (!logbuf)
 397                 return;
 398
 399         off = sdev_format_header(logbuf, logbuf_len,
 400                                  scmd_name(cmd), cmd->request->tag);
 401
 402         if (off >= logbuf_len)
 403                 goto out_printk;
 404
 405         if (msg) {
 406                 off += scnprintf(logbuf + off, logbuf_len - off,
 407                                  "%s: ", msg);
 408                 if (WARN_ON(off >= logbuf_len))
 409                         goto out_printk;
 410         }
 411         if (mlret_string)
 412                 off += scnprintf(logbuf + off, logbuf_len - off,
 413                                  "%s ", mlret_string);
 414         else
 415                 off += scnprintf(logbuf + off, logbuf_len - off,
 416                                  "UNKNOWN(0x%02x) ", disposition);
 417         if (WARN_ON(off >= logbuf_len))
 418                 goto out_printk;
 419
 420         off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");
 421         if (WARN_ON(off >= logbuf_len))
 422                 goto out_printk;
 423
 424         if (hb_string)
 425                 off += scnprintf(logbuf + off, logbuf_len - off,
 426                                  "hostbyte=%s ", hb_string);
 427         else
 428                 off += scnprintf(logbuf + off, logbuf_len - off,
 429                                  "hostbyte=0x%02x ", host_byte(cmd->result));
 430         if (WARN_ON(off >= logbuf_len))
 431                 goto out_printk;
 432
 433         if (db_string)
 434                 off += scnprintf(logbuf + off, logbuf_len - off,
 435                                  "driverbyte=%s ", db_string);
 436         else
 437                 off += scnprintf(logbuf + off, logbuf_len - off,
 438                                  "driverbyte=0x%02x ",
 439                                  driver_byte(cmd->result));
 440
 441         off += scnprintf(logbuf + off, logbuf_len - off,
 442                          "cmd_age=%lus", cmd_age);
 443
 444 out_printk:
 445         dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);
 446         scsi_log_release_buffer(logbuf);
 447 }
 448 EXPORT_SYMBOL(scsi_print_result);