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