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