Commit | Line | Data |
---|---|---|
55716d26 | 1 | // SPDX-License-Identifier: GPL-2.0-only |
ded85c19 HR |
2 | /* |
3 | * scsi_logging.c | |
4 | * | |
5 | * Copyright (C) 2014 SUSE Linux Products GmbH | |
6 | * Copyright (C) 2014 Hannes Reinecke <hare@suse.de> | |
ded85c19 HR |
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> | |
9e5ed2a5 | 15 | #include <scsi/scsi_eh.h> |
ded85c19 HR |
16 | #include <scsi/scsi_dbg.h> |
17 | ||
ded85c19 HR |
18 | static char *scsi_log_reserve_buffer(size_t *len) |
19 | { | |
dccc96ab BVA |
20 | *len = 128; |
21 | return kmalloc(*len, GFP_ATOMIC); | |
ded85c19 HR |
22 | } |
23 | ||
24 | static void scsi_log_release_buffer(char *bufptr) | |
25 | { | |
dccc96ab | 26 | kfree(bufptr); |
ded85c19 HR |
27 | } |
28 | ||
21045519 HR |
29 | static inline const char *scmd_name(const struct scsi_cmnd *scmd) |
30 | { | |
aa8e25e5 BVA |
31 | struct request *rq = scsi_cmd_to_rq((struct scsi_cmnd *)scmd); |
32 | ||
f3fa33ac CH |
33 | if (!rq->q->disk) |
34 | return NULL; | |
35 | return rq->q->disk->disk_name; | |
21045519 HR |
36 | } |
37 | ||
38 | static size_t sdev_format_header(char *logbuf, size_t logbuf_len, | |
39 | const char *name, int tag) | |
9e5ed2a5 HR |
40 | { |
41 | size_t off = 0; | |
42 | ||
21045519 | 43 | if (name) |
9e5ed2a5 | 44 | off += scnprintf(logbuf + off, logbuf_len - off, |
21045519 | 45 | "[%s] ", name); |
9e5ed2a5 HR |
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 | ||
9c4a6b1e HR |
56 | void sdev_prefix_printk(const char *level, const struct scsi_device *sdev, |
57 | const char *name, const char *fmt, ...) | |
ded85c19 HR |
58 | { |
59 | va_list args; | |
60 | char *logbuf; | |
61 | size_t off = 0, logbuf_len; | |
ded85c19 HR |
62 | |
63 | if (!sdev) | |
9c4a6b1e | 64 | return; |
ded85c19 HR |
65 | |
66 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
67 | if (!logbuf) | |
9c4a6b1e | 68 | return; |
ded85c19 HR |
69 | |
70 | if (name) | |
71 | off += scnprintf(logbuf + off, logbuf_len - off, | |
72 | "[%s] ", name); | |
9e5ed2a5 HR |
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 | } | |
9c4a6b1e | 78 | dev_printk(level, &sdev->sdev_gendev, "%s", logbuf); |
ded85c19 | 79 | scsi_log_release_buffer(logbuf); |
ded85c19 HR |
80 | } |
81 | EXPORT_SYMBOL(sdev_prefix_printk); | |
82 | ||
9c4a6b1e | 83 | void scmd_printk(const char *level, const struct scsi_cmnd *scmd, |
ded85c19 HR |
84 | const char *fmt, ...) |
85 | { | |
ded85c19 HR |
86 | va_list args; |
87 | char *logbuf; | |
88 | size_t off = 0, logbuf_len; | |
ded85c19 HR |
89 | |
90 | if (!scmd || !scmd->cmnd) | |
9c4a6b1e | 91 | return; |
ded85c19 HR |
92 | |
93 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
94 | if (!logbuf) | |
9c4a6b1e | 95 | return; |
21045519 | 96 | off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd), |
aa8e25e5 | 97 | scsi_cmd_to_rq((struct scsi_cmnd *)scmd)->tag); |
9e5ed2a5 HR |
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 | } | |
9c4a6b1e | 103 | dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf); |
ded85c19 | 104 | scsi_log_release_buffer(logbuf); |
ded85c19 HR |
105 | } |
106 | EXPORT_SYMBOL(scmd_printk); | |
9e5ed2a5 HR |
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(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 | ||
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 | ||
180 | void scsi_print_command(struct scsi_cmnd *cmd) | |
181 | { | |
9e5ed2a5 HR |
182 | int k; |
183 | char *logbuf; | |
184 | size_t off, logbuf_len; | |
185 | ||
186 | if (!cmd->cmnd) | |
187 | return; | |
188 | ||
189 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
190 | if (!logbuf) | |
191 | return; | |
192 | ||
21045519 | 193 | off = sdev_format_header(logbuf, logbuf_len, |
aa8e25e5 | 194 | scmd_name(cmd), scsi_cmd_to_rq(cmd)->tag); |
9e5ed2a5 HR |
195 | if (off >= logbuf_len) |
196 | goto out_printk; | |
197 | off += scnprintf(logbuf + off, logbuf_len - off, "CDB: "); | |
198 | if (WARN_ON(off >= logbuf_len)) | |
199 | goto out_printk; | |
200 | ||
201 | off += scsi_format_opcode_name(logbuf + off, logbuf_len - off, | |
202 | cmd->cmnd); | |
203 | if (off >= logbuf_len) | |
204 | goto out_printk; | |
205 | ||
206 | /* print out all bytes in cdb */ | |
207 | if (cmd->cmd_len > 16) { | |
208 | /* Print opcode in one line and use separate lines for CDB */ | |
209 | off += scnprintf(logbuf + off, logbuf_len - off, "\n"); | |
2fc583c4 | 210 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
9e5ed2a5 HR |
211 | for (k = 0; k < cmd->cmd_len; k += 16) { |
212 | size_t linelen = min(cmd->cmd_len - k, 16); | |
213 | ||
21045519 HR |
214 | off = sdev_format_header(logbuf, logbuf_len, |
215 | scmd_name(cmd), | |
aa8e25e5 | 216 | scsi_cmd_to_rq(cmd)->tag); |
9e5ed2a5 HR |
217 | if (!WARN_ON(off > logbuf_len - 58)) { |
218 | off += scnprintf(logbuf + off, logbuf_len - off, | |
219 | "CDB[%02x]: ", k); | |
220 | hex_dump_to_buffer(&cmd->cmnd[k], linelen, | |
221 | 16, 1, logbuf + off, | |
222 | logbuf_len - off, false); | |
223 | } | |
2fc583c4 | 224 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", |
9e5ed2a5 | 225 | logbuf); |
9e5ed2a5 | 226 | } |
811f3947 | 227 | goto out; |
9e5ed2a5 HR |
228 | } |
229 | if (!WARN_ON(off > logbuf_len - 49)) { | |
230 | off += scnprintf(logbuf + off, logbuf_len - off, " "); | |
231 | hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1, | |
232 | logbuf + off, logbuf_len - off, | |
233 | false); | |
234 | } | |
235 | out_printk: | |
2fc583c4 | 236 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
811f3947 | 237 | out: |
9e5ed2a5 HR |
238 | scsi_log_release_buffer(logbuf); |
239 | } | |
240 | EXPORT_SYMBOL(scsi_print_command); | |
21045519 HR |
241 | |
242 | static size_t | |
243 | scsi_format_extd_sense(char *buffer, size_t buf_len, | |
244 | unsigned char asc, unsigned char ascq) | |
245 | { | |
246 | size_t off = 0; | |
247 | const char *extd_sense_fmt = NULL; | |
248 | const char *extd_sense_str = scsi_extd_sense_format(asc, ascq, | |
249 | &extd_sense_fmt); | |
250 | ||
251 | if (extd_sense_str) { | |
252 | off = scnprintf(buffer, buf_len, "Add. Sense: %s", | |
253 | extd_sense_str); | |
254 | if (extd_sense_fmt) | |
255 | off += scnprintf(buffer + off, buf_len - off, | |
256 | "(%s%x)", extd_sense_fmt, ascq); | |
257 | } else { | |
258 | if (asc >= 0x80) | |
259 | off = scnprintf(buffer, buf_len, "<<vendor>>"); | |
260 | off += scnprintf(buffer + off, buf_len - off, | |
261 | "ASC=0x%x ", asc); | |
262 | if (ascq >= 0x80) | |
263 | off += scnprintf(buffer + off, buf_len - off, | |
264 | "<<vendor>>"); | |
265 | off += scnprintf(buffer + off, buf_len - off, | |
266 | "ASCQ=0x%x ", ascq); | |
267 | } | |
268 | return off; | |
269 | } | |
270 | ||
271 | static size_t | |
272 | scsi_format_sense_hdr(char *buffer, size_t buf_len, | |
273 | const struct scsi_sense_hdr *sshdr) | |
274 | { | |
275 | const char *sense_txt; | |
276 | size_t off; | |
277 | ||
278 | off = scnprintf(buffer, buf_len, "Sense Key : "); | |
279 | sense_txt = scsi_sense_key_string(sshdr->sense_key); | |
280 | if (sense_txt) | |
281 | off += scnprintf(buffer + off, buf_len - off, | |
282 | "%s ", sense_txt); | |
283 | else | |
284 | off += scnprintf(buffer + off, buf_len - off, | |
285 | "0x%x ", sshdr->sense_key); | |
286 | off += scnprintf(buffer + off, buf_len - off, | |
287 | scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] "); | |
288 | ||
289 | if (sshdr->response_code >= 0x72) | |
290 | off += scnprintf(buffer + off, buf_len - off, "[descriptor] "); | |
291 | return off; | |
292 | } | |
293 | ||
294 | static void | |
295 | scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag, | |
296 | const unsigned char *sense_buffer, int sense_len) | |
297 | { | |
298 | char *logbuf; | |
299 | size_t logbuf_len; | |
300 | int i; | |
301 | ||
302 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
303 | if (!logbuf) | |
304 | return; | |
305 | ||
306 | for (i = 0; i < sense_len; i += 16) { | |
307 | int len = min(sense_len - i, 16); | |
308 | size_t off; | |
309 | ||
310 | off = sdev_format_header(logbuf, logbuf_len, | |
311 | name, tag); | |
312 | hex_dump_to_buffer(&sense_buffer[i], len, 16, 1, | |
313 | logbuf + off, logbuf_len - off, | |
314 | false); | |
2fc583c4 | 315 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
316 | } |
317 | scsi_log_release_buffer(logbuf); | |
318 | } | |
319 | ||
320 | static void | |
321 | scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name, | |
322 | int tag, const struct scsi_sense_hdr *sshdr) | |
323 | { | |
324 | char *logbuf; | |
325 | size_t off, logbuf_len; | |
326 | ||
327 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
328 | if (!logbuf) | |
329 | return; | |
330 | off = sdev_format_header(logbuf, logbuf_len, name, tag); | |
331 | off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr); | |
2fc583c4 | 332 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
333 | scsi_log_release_buffer(logbuf); |
334 | ||
335 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
336 | if (!logbuf) | |
337 | return; | |
338 | off = sdev_format_header(logbuf, logbuf_len, name, tag); | |
339 | off += scsi_format_extd_sense(logbuf + off, logbuf_len - off, | |
340 | sshdr->asc, sshdr->ascq); | |
2fc583c4 | 341 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
342 | scsi_log_release_buffer(logbuf); |
343 | } | |
344 | ||
345 | static void | |
346 | scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag, | |
347 | const unsigned char *sense_buffer, int sense_len) | |
348 | { | |
349 | struct scsi_sense_hdr sshdr; | |
350 | ||
351 | if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) | |
352 | scsi_log_print_sense_hdr(sdev, name, tag, &sshdr); | |
353 | else | |
354 | scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len); | |
355 | } | |
356 | ||
357 | /* | |
358 | * Print normalized SCSI sense header with a prefix. | |
359 | */ | |
360 | void | |
361 | scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name, | |
362 | const struct scsi_sense_hdr *sshdr) | |
363 | { | |
364 | scsi_log_print_sense_hdr(sdev, name, -1, sshdr); | |
365 | } | |
366 | EXPORT_SYMBOL(scsi_print_sense_hdr); | |
367 | ||
368 | /* Normalize and print sense buffer with name prefix */ | |
369 | void __scsi_print_sense(const struct scsi_device *sdev, const char *name, | |
370 | const unsigned char *sense_buffer, int sense_len) | |
371 | { | |
372 | scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len); | |
373 | } | |
374 | EXPORT_SYMBOL(__scsi_print_sense); | |
375 | ||
376 | /* Normalize and print sense buffer in SCSI command */ | |
377 | void scsi_print_sense(const struct scsi_cmnd *cmd) | |
378 | { | |
aa8e25e5 BVA |
379 | scsi_log_print_sense(cmd->device, scmd_name(cmd), |
380 | scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag, | |
21045519 HR |
381 | cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE); |
382 | } | |
383 | EXPORT_SYMBOL(scsi_print_sense); | |
026f8da8 HR |
384 | |
385 | void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg, | |
386 | int disposition) | |
387 | { | |
388 | char *logbuf; | |
389 | size_t off, logbuf_len; | |
390 | const char *mlret_string = scsi_mlreturn_string(disposition); | |
391 | const char *hb_string = scsi_hostbyte_string(cmd->result); | |
8ee132b3 | 392 | unsigned long cmd_age = (jiffies - cmd->jiffies_at_alloc) / HZ; |
026f8da8 HR |
393 | |
394 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
395 | if (!logbuf) | |
396 | return; | |
397 | ||
aa8e25e5 BVA |
398 | off = sdev_format_header(logbuf, logbuf_len, scmd_name(cmd), |
399 | scsi_cmd_to_rq((struct scsi_cmnd *)cmd)->tag); | |
026f8da8 HR |
400 | |
401 | if (off >= logbuf_len) | |
402 | goto out_printk; | |
403 | ||
404 | if (msg) { | |
405 | off += scnprintf(logbuf + off, logbuf_len - off, | |
406 | "%s: ", msg); | |
407 | if (WARN_ON(off >= logbuf_len)) | |
408 | goto out_printk; | |
409 | } | |
410 | if (mlret_string) | |
411 | off += scnprintf(logbuf + off, logbuf_len - off, | |
412 | "%s ", mlret_string); | |
413 | else | |
414 | off += scnprintf(logbuf + off, logbuf_len - off, | |
415 | "UNKNOWN(0x%02x) ", disposition); | |
416 | if (WARN_ON(off >= logbuf_len)) | |
417 | goto out_printk; | |
418 | ||
419 | off += scnprintf(logbuf + off, logbuf_len - off, "Result: "); | |
420 | if (WARN_ON(off >= logbuf_len)) | |
421 | goto out_printk; | |
422 | ||
423 | if (hb_string) | |
424 | off += scnprintf(logbuf + off, logbuf_len - off, | |
425 | "hostbyte=%s ", hb_string); | |
426 | else | |
427 | off += scnprintf(logbuf + off, logbuf_len - off, | |
428 | "hostbyte=0x%02x ", host_byte(cmd->result)); | |
429 | if (WARN_ON(off >= logbuf_len)) | |
430 | goto out_printk; | |
431 | ||
54c29086 HR |
432 | off += scnprintf(logbuf + off, logbuf_len - off, |
433 | "driverbyte=DRIVER_OK "); | |
8ee132b3 MG |
434 | |
435 | off += scnprintf(logbuf + off, logbuf_len - off, | |
436 | "cmd_age=%lus", cmd_age); | |
437 | ||
026f8da8 | 438 | out_printk: |
2fc583c4 | 439 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
026f8da8 HR |
440 | scsi_log_release_buffer(logbuf); |
441 | } | |
442 | EXPORT_SYMBOL(scsi_print_result); |