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(size: *len, GFP_ATOMIC); |
22 | } |
23 | |
24 | static void scsi_log_release_buffer(char *bufptr) |
25 | { |
26 | kfree(objp: bufptr); |
27 | } |
28 | |
29 | static inline const char *scmd_name(const struct scsi_cmnd *scmd) |
30 | { |
31 | struct request *rq = scsi_cmd_to_rq(scmd: (struct scsi_cmnd *)scmd); |
32 | |
33 | if (!rq->q || !rq->q->disk) |
34 | return NULL; |
35 | return rq->q->disk->disk_name; |
36 | } |
37 | |
38 | static size_t (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(buf: logbuf + off, size: logbuf_len - off, |
45 | fmt: "[%s] " , name); |
46 | |
47 | if (WARN_ON(off >= logbuf_len)) |
48 | return off; |
49 | |
50 | if (tag >= 0) |
51 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
52 | fmt: "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(len: &logbuf_len); |
67 | if (!logbuf) |
68 | return; |
69 | |
70 | if (name) |
71 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
72 | fmt: "[%s] " , name); |
73 | if (!WARN_ON(off >= logbuf_len)) { |
74 | va_start(args, fmt); |
75 | off += vscnprintf(buf: logbuf + off, size: logbuf_len - off, fmt, args); |
76 | va_end(args); |
77 | } |
78 | dev_printk(level, &sdev->sdev_gendev, "%s" , logbuf); |
79 | scsi_log_release_buffer(bufptr: 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) |
91 | return; |
92 | |
93 | logbuf = scsi_log_reserve_buffer(len: &logbuf_len); |
94 | if (!logbuf) |
95 | return; |
96 | off = sdev_format_header(logbuf, logbuf_len, name: scmd_name(scmd), |
97 | tag: scsi_cmd_to_rq(scmd: (struct scsi_cmnd *)scmd)->tag); |
98 | if (off < logbuf_len) { |
99 | va_start(args, fmt); |
100 | off += vscnprintf(buf: logbuf + off, size: 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(bufptr: 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(hdr: cdbp); |
118 | |
119 | if (len < 10) { |
120 | off = scnprintf(buf: buffer, size: buf_len, |
121 | fmt: "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(buf: buffer, size: buf_len, fmt: "%s" , cdb_name); |
132 | else { |
133 | off = scnprintf(buf: buffer, size: buf_len, fmt: "opcode=0x%x" , cdb0); |
134 | if (WARN_ON(off >= buf_len)) |
135 | return off; |
136 | if (cdb0 >= VENDOR_SPECIFIC_CDB) |
137 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
138 | fmt: " (vendor)" ); |
139 | else if (cdb0 >= 0x60 && cdb0 < 0x7e) |
140 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
141 | fmt: " (reserved)" ); |
142 | } |
143 | } else { |
144 | if (sa_name) |
145 | off = scnprintf(buf: buffer, size: buf_len, fmt: "%s" , sa_name); |
146 | else if (cdb_name) |
147 | off = scnprintf(buf: buffer, size: buf_len, fmt: "%s, sa=0x%x" , |
148 | cdb_name, sa); |
149 | else |
150 | off = scnprintf(buf: buffer, size: buf_len, |
151 | fmt: "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(buffer: logbuf, buf_len: logbuf_len, cdbp: cdb); |
164 | if (off >= logbuf_len) |
165 | return off; |
166 | len = scsi_command_size(cmnd: 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(buf: logbuf + off, size: logbuf_len - off, |
174 | fmt: " %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 | logbuf = scsi_log_reserve_buffer(len: &logbuf_len); |
187 | if (!logbuf) |
188 | return; |
189 | |
190 | off = sdev_format_header(logbuf, logbuf_len, |
191 | name: scmd_name(scmd: cmd), tag: scsi_cmd_to_rq(scmd: cmd)->tag); |
192 | if (off >= logbuf_len) |
193 | goto out_printk; |
194 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, fmt: "CDB: " ); |
195 | if (WARN_ON(off >= logbuf_len)) |
196 | goto out_printk; |
197 | |
198 | off += scsi_format_opcode_name(buffer: logbuf + off, buf_len: logbuf_len - off, |
199 | cdbp: 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(buf: logbuf + off, size: logbuf_len - off, fmt: "\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 | name: scmd_name(scmd: cmd), |
213 | tag: scsi_cmd_to_rq(scmd: cmd)->tag); |
214 | if (!WARN_ON(off > logbuf_len - 58)) { |
215 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
216 | fmt: "CDB[%02x]: " , k); |
217 | hex_dump_to_buffer(buf: &cmd->cmnd[k], len: linelen, |
218 | rowsize: 16, groupsize: 1, linebuf: logbuf + off, |
219 | linebuflen: logbuf_len - off, ascii: 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(buf: logbuf + off, size: logbuf_len - off, fmt: " " ); |
228 | hex_dump_to_buffer(buf: cmd->cmnd, len: cmd->cmd_len, rowsize: 16, groupsize: 1, |
229 | linebuf: logbuf + off, linebuflen: logbuf_len - off, |
230 | ascii: false); |
231 | } |
232 | out_printk: |
233 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s" , logbuf); |
234 | out: |
235 | scsi_log_release_buffer(bufptr: logbuf); |
236 | } |
237 | EXPORT_SYMBOL(scsi_print_command); |
238 | |
239 | static size_t |
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(buf: buffer, size: buf_len, fmt: "Add. Sense: %s" , |
250 | extd_sense_str); |
251 | if (extd_sense_fmt) |
252 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
253 | fmt: "(%s%x)" , extd_sense_fmt, ascq); |
254 | } else { |
255 | if (asc >= 0x80) |
256 | off = scnprintf(buf: buffer, size: buf_len, fmt: "<<vendor>>" ); |
257 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
258 | fmt: "ASC=0x%x " , asc); |
259 | if (ascq >= 0x80) |
260 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
261 | fmt: "<<vendor>>" ); |
262 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
263 | fmt: "ASCQ=0x%x " , ascq); |
264 | } |
265 | return off; |
266 | } |
267 | |
268 | static size_t |
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(buf: buffer, size: buf_len, fmt: "Sense Key : " ); |
276 | sense_txt = scsi_sense_key_string(sshdr->sense_key); |
277 | if (sense_txt) |
278 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
279 | fmt: "%s " , sense_txt); |
280 | else |
281 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
282 | fmt: "0x%x " , sshdr->sense_key); |
283 | off += scnprintf(buf: buffer + off, size: buf_len - off, |
284 | fmt: scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] " ); |
285 | |
286 | if (sshdr->response_code >= 0x72) |
287 | off += scnprintf(buf: buffer + off, size: buf_len - off, fmt: "[descriptor] " ); |
288 | return off; |
289 | } |
290 | |
291 | static void |
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(len: &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(buf: &sense_buffer[i], len, rowsize: 16, groupsize: 1, |
310 | linebuf: logbuf + off, linebuflen: logbuf_len - off, |
311 | ascii: false); |
312 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s" , logbuf); |
313 | } |
314 | scsi_log_release_buffer(bufptr: logbuf); |
315 | } |
316 | |
317 | static void |
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(len: &logbuf_len); |
325 | if (!logbuf) |
326 | return; |
327 | off = sdev_format_header(logbuf, logbuf_len, name, tag); |
328 | off += scsi_format_sense_hdr(buffer: logbuf + off, buf_len: logbuf_len - off, sshdr); |
329 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s" , logbuf); |
330 | scsi_log_release_buffer(bufptr: logbuf); |
331 | |
332 | logbuf = scsi_log_reserve_buffer(len: &logbuf_len); |
333 | if (!logbuf) |
334 | return; |
335 | off = sdev_format_header(logbuf, logbuf_len, name, tag); |
336 | off += scsi_format_extd_sense(buffer: logbuf + off, buf_len: logbuf_len - off, |
337 | asc: sshdr->asc, ascq: sshdr->ascq); |
338 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s" , logbuf); |
339 | scsi_log_release_buffer(bufptr: logbuf); |
340 | } |
341 | |
342 | static void |
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, sb_len: sense_len, sshdr: &sshdr)) |
349 | scsi_log_print_sense_hdr(sdev, name, tag, sshdr: &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 |
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, tag: -1, sshdr); |
362 | } |
363 | EXPORT_SYMBOL(scsi_print_sense_hdr); |
364 | |
365 | /* Normalize and print sense buffer with name prefix */ |
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, tag: -1, sense_buffer, sense_len); |
370 | } |
371 | EXPORT_SYMBOL(__scsi_print_sense); |
372 | |
373 | /* Normalize and print sense buffer in SCSI command */ |
374 | void scsi_print_sense(const struct scsi_cmnd *cmd) |
375 | { |
376 | scsi_log_print_sense(sdev: cmd->device, name: scmd_name(scmd: cmd), |
377 | tag: scsi_cmd_to_rq(scmd: (struct scsi_cmnd *)cmd)->tag, |
378 | sense_buffer: cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE); |
379 | } |
380 | EXPORT_SYMBOL(scsi_print_sense); |
381 | |
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(len: &logbuf_len); |
392 | if (!logbuf) |
393 | return; |
394 | |
395 | off = sdev_format_header(logbuf, logbuf_len, name: scmd_name(scmd: cmd), |
396 | tag: scsi_cmd_to_rq(scmd: (struct scsi_cmnd *)cmd)->tag); |
397 | |
398 | if (off >= logbuf_len) |
399 | goto out_printk; |
400 | |
401 | if (msg) { |
402 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
403 | fmt: "%s: " , msg); |
404 | if (WARN_ON(off >= logbuf_len)) |
405 | goto out_printk; |
406 | } |
407 | if (mlret_string) |
408 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
409 | fmt: "%s " , mlret_string); |
410 | else |
411 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
412 | fmt: "UNKNOWN(0x%02x) " , disposition); |
413 | if (WARN_ON(off >= logbuf_len)) |
414 | goto out_printk; |
415 | |
416 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, fmt: "Result: " ); |
417 | if (WARN_ON(off >= logbuf_len)) |
418 | goto out_printk; |
419 | |
420 | if (hb_string) |
421 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
422 | fmt: "hostbyte=%s " , hb_string); |
423 | else |
424 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
425 | fmt: "hostbyte=0x%02x " , host_byte(cmd->result)); |
426 | if (WARN_ON(off >= logbuf_len)) |
427 | goto out_printk; |
428 | |
429 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
430 | fmt: "driverbyte=DRIVER_OK " ); |
431 | |
432 | off += scnprintf(buf: logbuf + off, size: logbuf_len - off, |
433 | fmt: "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(bufptr: logbuf); |
438 | } |
439 | EXPORT_SYMBOL(scsi_print_result); |
440 | |