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 scsi_log_reserve_buffer(size_t * len)18 static char *scsi_log_reserve_buffer(size_t *len) 19 { 20 *len = 128; 21 return kmalloc(*len, GFP_ATOMIC); 22 } 23 scsi_log_release_buffer(char * bufptr)24 static void scsi_log_release_buffer(char *bufptr) 25 { 26 kfree(bufptr); 27 } 28 scmd_name(const struct scsi_cmnd * scmd)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 || !rq->q->disk) 34 return NULL; 35 return rq->q->disk->disk_name; 36 } 37 sdev_format_header(char * logbuf,size_t logbuf_len,const char * name,int tag)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 sdev_prefix_printk(const char * level,const struct scsi_device * sdev,const char * name,const char * fmt,...)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 scmd_printk(const char * level,const struct scsi_cmnd * scmd,const char * fmt,...)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) 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 scsi_format_opcode_name(char * buffer,size_t buf_len,const unsigned char * cdbp)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 __scsi_format_command(char * logbuf,size_t logbuf_len,const unsigned char * cdb,size_t cdb_len)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 scsi_print_command(struct scsi_cmnd * cmd)180 void 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 } 232 out_printk: 233 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); 234 out: 235 scsi_log_release_buffer(logbuf); 236 } 237 EXPORT_SYMBOL(scsi_print_command); 238 239 static size_t scsi_format_extd_sense(char * buffer,size_t buf_len,unsigned char asc,unsigned char ascq)240 scsi_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 268 static size_t scsi_format_sense_hdr(char * buffer,size_t buf_len,const struct scsi_sense_hdr * sshdr)269 scsi_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 else 281 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 291 static void scsi_log_dump_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)292 scsi_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 317 static void scsi_log_print_sense_hdr(const struct scsi_device * sdev,const char * name,int tag,const struct scsi_sense_hdr * sshdr)318 scsi_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 342 static void scsi_log_print_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)343 scsi_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 else 351 scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len); 352 } 353 354 /* 355 * Print normalized SCSI sense header with a prefix. 356 */ 357 void scsi_print_sense_hdr(const struct scsi_device * sdev,const char * name,const struct scsi_sense_hdr * sshdr)358 scsi_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 } 363 EXPORT_SYMBOL(scsi_print_sense_hdr); 364 365 /* Normalize and print sense buffer with name prefix */ __scsi_print_sense(const struct scsi_device * sdev,const char * name,const unsigned char * sense_buffer,int sense_len)366 void __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 } 371 EXPORT_SYMBOL(__scsi_print_sense); 372 373 /* Normalize and print sense buffer in SCSI command */ scsi_print_sense(const struct scsi_cmnd * cmd)374 void 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 } 380 EXPORT_SYMBOL(scsi_print_sense); 381 scsi_print_result(const struct scsi_cmnd * cmd,const char * msg,int disposition)382 void 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 else 411 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 else 424 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 435 out_printk: 436 dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); 437 scsi_log_release_buffer(logbuf); 438 } 439 EXPORT_SYMBOL(scsi_print_result); 440