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 return rq->rq_disk ? rq->rq_disk->disk_name : NULL;
34 }
35
sdev_format_header(char * logbuf,size_t logbuf_len,const char * name,int tag)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
sdev_prefix_printk(const char * level,const struct scsi_device * sdev,const char * name,const char * fmt,...)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
scmd_printk(const char * level,const struct scsi_cmnd * scmd,const char * fmt,...)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
scsi_format_opcode_name(char * buffer,size_t buf_len,const unsigned char * cdbp)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
__scsi_format_command(char * logbuf,size_t logbuf_len,const unsigned char * cdb,size_t cdb_len)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
scsi_print_command(struct scsi_cmnd * cmd)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
scsi_format_extd_sense(char * buffer,size_t buf_len,unsigned char asc,unsigned char ascq)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
scsi_format_sense_hdr(char * buffer,size_t buf_len,const struct scsi_sense_hdr * sshdr)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
scsi_log_dump_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)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
scsi_log_print_sense_hdr(const struct scsi_device * sdev,const char * name,int tag,const struct scsi_sense_hdr * sshdr)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
scsi_log_print_sense(const struct scsi_device * sdev,const char * name,int tag,const unsigned char * sense_buffer,int sense_len)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
scsi_print_sense_hdr(const struct scsi_device * sdev,const char * name,const struct scsi_sense_hdr * sshdr)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 */
__scsi_print_sense(const struct scsi_device * sdev,const char * name,const unsigned char * sense_buffer,int sense_len)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 */
scsi_print_sense(const struct scsi_cmnd * cmd)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
scsi_print_result(const struct scsi_cmnd * cmd,const char * msg,int disposition)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);
441