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