440 lines · c
1// SPDX-License-Identifier: GPL-2.0-only2/*3 * scsi_logging.c4 *5 * Copyright (C) 2014 SUSE Linux Products GmbH6 * 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 18static char *scsi_log_reserve_buffer(size_t *len)19{20 *len = 128;21 return kmalloc(*len, GFP_ATOMIC);22}23 24static void scsi_log_release_buffer(char *bufptr)25{26 kfree(bufptr);27}28 29static 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 || !rq->q->disk)34 return NULL;35 return rq->q->disk->disk_name;36}37 38static 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 56void 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}81EXPORT_SYMBOL(sdev_prefix_printk);82 83void 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)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}106EXPORT_SYMBOL(scmd_printk);107 108static 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 } else127 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 else150 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 157size_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}178EXPORT_SYMBOL(__scsi_format_command);179 180void scsi_print_command(struct scsi_cmnd *cmd)181{182 int k;183 char *logbuf;184 size_t off, logbuf_len;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), scsi_cmd_to_rq(cmd)->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 for (k = 0; k < cmd->cmd_len; k += 16) {209 size_t linelen = min(cmd->cmd_len - k, 16);210 211 off = sdev_format_header(logbuf, logbuf_len,212 scmd_name(cmd),213 scsi_cmd_to_rq(cmd)->tag);214 if (!WARN_ON(off > logbuf_len - 58)) {215 off += scnprintf(logbuf + off, logbuf_len - off,216 "CDB[%02x]: ", k);217 hex_dump_to_buffer(&cmd->cmnd[k], linelen,218 16, 1, logbuf + off,219 logbuf_len - off, false);220 }221 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s",222 logbuf);223 }224 goto out;225 }226 if (!WARN_ON(off > logbuf_len - 49)) {227 off += scnprintf(logbuf + off, logbuf_len - off, " ");228 hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1,229 logbuf + off, logbuf_len - off,230 false);231 }232out_printk:233 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);234out:235 scsi_log_release_buffer(logbuf);236}237EXPORT_SYMBOL(scsi_print_command);238 239static size_t240scsi_format_extd_sense(char *buffer, size_t buf_len,241 unsigned char asc, unsigned char ascq)242{243 size_t off = 0;244 const char *extd_sense_fmt = NULL;245 const char *extd_sense_str = scsi_extd_sense_format(asc, ascq,246 &extd_sense_fmt);247 248 if (extd_sense_str) {249 off = scnprintf(buffer, buf_len, "Add. Sense: %s",250 extd_sense_str);251 if (extd_sense_fmt)252 off += scnprintf(buffer + off, buf_len - off,253 "(%s%x)", extd_sense_fmt, ascq);254 } else {255 if (asc >= 0x80)256 off = scnprintf(buffer, buf_len, "<<vendor>>");257 off += scnprintf(buffer + off, buf_len - off,258 "ASC=0x%x ", asc);259 if (ascq >= 0x80)260 off += scnprintf(buffer + off, buf_len - off,261 "<<vendor>>");262 off += scnprintf(buffer + off, buf_len - off,263 "ASCQ=0x%x ", ascq);264 }265 return off;266}267 268static size_t269scsi_format_sense_hdr(char *buffer, size_t buf_len,270 const struct scsi_sense_hdr *sshdr)271{272 const char *sense_txt;273 size_t off;274 275 off = scnprintf(buffer, buf_len, "Sense Key : ");276 sense_txt = scsi_sense_key_string(sshdr->sense_key);277 if (sense_txt)278 off += scnprintf(buffer + off, buf_len - off,279 "%s ", sense_txt);280 else281 off += scnprintf(buffer + off, buf_len - off,282 "0x%x ", sshdr->sense_key);283 off += scnprintf(buffer + off, buf_len - off,284 scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] ");285 286 if (sshdr->response_code >= 0x72)287 off += scnprintf(buffer + off, buf_len - off, "[descriptor] ");288 return off;289}290 291static void292scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag,293 const unsigned char *sense_buffer, int sense_len)294{295 char *logbuf;296 size_t logbuf_len;297 int i;298 299 logbuf = scsi_log_reserve_buffer(&logbuf_len);300 if (!logbuf)301 return;302 303 for (i = 0; i < sense_len; i += 16) {304 int len = min(sense_len - i, 16);305 size_t off;306 307 off = sdev_format_header(logbuf, logbuf_len,308 name, tag);309 hex_dump_to_buffer(&sense_buffer[i], len, 16, 1,310 logbuf + off, logbuf_len - off,311 false);312 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);313 }314 scsi_log_release_buffer(logbuf);315}316 317static void318scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name,319 int tag, const struct scsi_sense_hdr *sshdr)320{321 char *logbuf;322 size_t off, logbuf_len;323 324 logbuf = scsi_log_reserve_buffer(&logbuf_len);325 if (!logbuf)326 return;327 off = sdev_format_header(logbuf, logbuf_len, name, tag);328 off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr);329 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);330 scsi_log_release_buffer(logbuf);331 332 logbuf = scsi_log_reserve_buffer(&logbuf_len);333 if (!logbuf)334 return;335 off = sdev_format_header(logbuf, logbuf_len, name, tag);336 off += scsi_format_extd_sense(logbuf + off, logbuf_len - off,337 sshdr->asc, sshdr->ascq);338 dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf);339 scsi_log_release_buffer(logbuf);340}341 342static void343scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag,344 const unsigned char *sense_buffer, int sense_len)345{346 struct scsi_sense_hdr sshdr;347 348 if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr))349 scsi_log_print_sense_hdr(sdev, name, tag, &sshdr);350 else351 scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len);352}353 354/*355 * Print normalized SCSI sense header with a prefix.356 */357void358scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name,359 const struct scsi_sense_hdr *sshdr)360{361 scsi_log_print_sense_hdr(sdev, name, -1, sshdr);362}363EXPORT_SYMBOL(scsi_print_sense_hdr);364 365/* Normalize and print sense buffer with name prefix */366void __scsi_print_sense(const struct scsi_device *sdev, const char *name,367 const unsigned char *sense_buffer, int sense_len)368{369 scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len);370}371EXPORT_SYMBOL(__scsi_print_sense);372 373/* Normalize and print sense buffer in SCSI command */374void scsi_print_sense(const struct scsi_cmnd *cmd)375{376 scsi_log_print_sense(cmd->device, scmd_name(cmd),377 scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag,378 cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE);379}380EXPORT_SYMBOL(scsi_print_sense);381 382void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg,383 int disposition)384{385 char *logbuf;386 size_t off, logbuf_len;387 const char *mlret_string = scsi_mlreturn_string(disposition);388 const char *hb_string = scsi_hostbyte_string(cmd->result);389 unsigned long cmd_age = (jiffies - cmd->jiffies_at_alloc) / HZ;390 391 logbuf = scsi_log_reserve_buffer(&logbuf_len);392 if (!logbuf)393 return;394 395 off = sdev_format_header(logbuf, logbuf_len, scmd_name(cmd),396 scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag);397 398 if (off >= logbuf_len)399 goto out_printk;400 401 if (msg) {402 off += scnprintf(logbuf + off, logbuf_len - off,403 "%s: ", msg);404 if (WARN_ON(off >= logbuf_len))405 goto out_printk;406 }407 if (mlret_string)408 off += scnprintf(logbuf + off, logbuf_len - off,409 "%s ", mlret_string);410 else411 off += scnprintf(logbuf + off, logbuf_len - off,412 "UNKNOWN(0x%02x) ", disposition);413 if (WARN_ON(off >= logbuf_len))414 goto out_printk;415 416 off += scnprintf(logbuf + off, logbuf_len - off, "Result: ");417 if (WARN_ON(off >= logbuf_len))418 goto out_printk;419 420 if (hb_string)421 off += scnprintf(logbuf + off, logbuf_len - off,422 "hostbyte=%s ", hb_string);423 else424 off += scnprintf(logbuf + off, logbuf_len - off,425 "hostbyte=0x%02x ", host_byte(cmd->result));426 if (WARN_ON(off >= logbuf_len))427 goto out_printk;428 429 off += scnprintf(logbuf + off, logbuf_len - off,430 "driverbyte=DRIVER_OK ");431 432 off += scnprintf(logbuf + off, logbuf_len - off,433 "cmd_age=%lus", cmd_age);434 435out_printk:436 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf);437 scsi_log_release_buffer(logbuf);438}439EXPORT_SYMBOL(scsi_print_result);440