Commit | Line | Data |
---|---|---|
ded85c19 HR |
1 | /* |
2 | * scsi_logging.c | |
3 | * | |
4 | * Copyright (C) 2014 SUSE Linux Products GmbH | |
5 | * Copyright (C) 2014 Hannes Reinecke <hare@suse.de> | |
6 | * | |
7 | * This file is released under the GPLv2 | |
8 | */ | |
9 | ||
10 | #include <linux/kernel.h> | |
11 | #include <linux/atomic.h> | |
12 | ||
13 | #include <scsi/scsi.h> | |
14 | #include <scsi/scsi_cmnd.h> | |
15 | #include <scsi/scsi_device.h> | |
9e5ed2a5 | 16 | #include <scsi/scsi_eh.h> |
ded85c19 HR |
17 | #include <scsi/scsi_dbg.h> |
18 | ||
19 | #define SCSI_LOG_SPOOLSIZE 4096 | |
ded85c19 HR |
20 | |
21 | #if (SCSI_LOG_SPOOLSIZE / SCSI_LOG_BUFSIZE) > BITS_PER_LONG | |
22 | #warning SCSI logging bitmask too large | |
23 | #endif | |
24 | ||
25 | struct scsi_log_buf { | |
26 | char buffer[SCSI_LOG_SPOOLSIZE]; | |
27 | unsigned long map; | |
28 | }; | |
29 | ||
30 | static DEFINE_PER_CPU(struct scsi_log_buf, scsi_format_log); | |
31 | ||
32 | static char *scsi_log_reserve_buffer(size_t *len) | |
33 | { | |
34 | struct scsi_log_buf *buf; | |
35 | unsigned long map_bits = sizeof(buf->buffer) / SCSI_LOG_BUFSIZE; | |
36 | unsigned long idx = 0; | |
37 | ||
38 | preempt_disable(); | |
39 | buf = this_cpu_ptr(&scsi_format_log); | |
40 | idx = find_first_zero_bit(&buf->map, map_bits); | |
41 | if (likely(idx < map_bits)) { | |
42 | while (test_and_set_bit(idx, &buf->map)) { | |
43 | idx = find_next_zero_bit(&buf->map, map_bits, idx); | |
44 | if (idx >= map_bits) | |
45 | break; | |
46 | } | |
47 | } | |
48 | if (WARN_ON(idx >= map_bits)) { | |
49 | preempt_enable(); | |
50 | return NULL; | |
51 | } | |
52 | *len = SCSI_LOG_BUFSIZE; | |
53 | return buf->buffer + idx * SCSI_LOG_BUFSIZE; | |
54 | } | |
55 | ||
56 | static void scsi_log_release_buffer(char *bufptr) | |
57 | { | |
58 | struct scsi_log_buf *buf; | |
59 | unsigned long idx; | |
60 | int ret; | |
61 | ||
62 | buf = this_cpu_ptr(&scsi_format_log); | |
63 | if (bufptr >= buf->buffer && | |
64 | bufptr < buf->buffer + SCSI_LOG_SPOOLSIZE) { | |
65 | idx = (bufptr - buf->buffer) / SCSI_LOG_BUFSIZE; | |
66 | ret = test_and_clear_bit(idx, &buf->map); | |
67 | WARN_ON(!ret); | |
68 | } | |
69 | preempt_enable(); | |
70 | } | |
71 | ||
21045519 HR |
72 | static inline const char *scmd_name(const struct scsi_cmnd *scmd) |
73 | { | |
74 | return scmd->request->rq_disk ? | |
75 | scmd->request->rq_disk->disk_name : NULL; | |
76 | } | |
77 | ||
78 | static size_t sdev_format_header(char *logbuf, size_t logbuf_len, | |
79 | const char *name, int tag) | |
9e5ed2a5 HR |
80 | { |
81 | size_t off = 0; | |
82 | ||
21045519 | 83 | if (name) |
9e5ed2a5 | 84 | off += scnprintf(logbuf + off, logbuf_len - off, |
21045519 | 85 | "[%s] ", name); |
9e5ed2a5 HR |
86 | |
87 | if (WARN_ON(off >= logbuf_len)) | |
88 | return off; | |
89 | ||
90 | if (tag >= 0) | |
91 | off += scnprintf(logbuf + off, logbuf_len - off, | |
92 | "tag#%d ", tag); | |
93 | return off; | |
94 | } | |
95 | ||
9c4a6b1e HR |
96 | void sdev_prefix_printk(const char *level, const struct scsi_device *sdev, |
97 | const char *name, const char *fmt, ...) | |
ded85c19 HR |
98 | { |
99 | va_list args; | |
100 | char *logbuf; | |
101 | size_t off = 0, logbuf_len; | |
ded85c19 HR |
102 | |
103 | if (!sdev) | |
9c4a6b1e | 104 | return; |
ded85c19 HR |
105 | |
106 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
107 | if (!logbuf) | |
9c4a6b1e | 108 | return; |
ded85c19 HR |
109 | |
110 | if (name) | |
111 | off += scnprintf(logbuf + off, logbuf_len - off, | |
112 | "[%s] ", name); | |
9e5ed2a5 HR |
113 | if (!WARN_ON(off >= logbuf_len)) { |
114 | va_start(args, fmt); | |
115 | off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); | |
116 | va_end(args); | |
117 | } | |
9c4a6b1e | 118 | dev_printk(level, &sdev->sdev_gendev, "%s", logbuf); |
ded85c19 | 119 | scsi_log_release_buffer(logbuf); |
ded85c19 HR |
120 | } |
121 | EXPORT_SYMBOL(sdev_prefix_printk); | |
122 | ||
9c4a6b1e | 123 | void scmd_printk(const char *level, const struct scsi_cmnd *scmd, |
ded85c19 HR |
124 | const char *fmt, ...) |
125 | { | |
ded85c19 HR |
126 | va_list args; |
127 | char *logbuf; | |
128 | size_t off = 0, logbuf_len; | |
ded85c19 HR |
129 | |
130 | if (!scmd || !scmd->cmnd) | |
9c4a6b1e | 131 | return; |
ded85c19 HR |
132 | |
133 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
134 | if (!logbuf) | |
9c4a6b1e | 135 | return; |
21045519 | 136 | off = sdev_format_header(logbuf, logbuf_len, scmd_name(scmd), |
9e5ed2a5 HR |
137 | scmd->request->tag); |
138 | if (off < logbuf_len) { | |
139 | va_start(args, fmt); | |
140 | off += vscnprintf(logbuf + off, logbuf_len - off, fmt, args); | |
141 | va_end(args); | |
142 | } | |
9c4a6b1e | 143 | dev_printk(level, &scmd->device->sdev_gendev, "%s", logbuf); |
ded85c19 | 144 | scsi_log_release_buffer(logbuf); |
ded85c19 HR |
145 | } |
146 | EXPORT_SYMBOL(scmd_printk); | |
9e5ed2a5 HR |
147 | |
148 | static size_t scsi_format_opcode_name(char *buffer, size_t buf_len, | |
149 | const unsigned char *cdbp) | |
150 | { | |
151 | int sa, cdb0; | |
152 | const char *cdb_name = NULL, *sa_name = NULL; | |
153 | size_t off; | |
154 | ||
155 | cdb0 = cdbp[0]; | |
156 | if (cdb0 == VARIABLE_LENGTH_CMD) { | |
157 | int len = scsi_varlen_cdb_length(cdbp); | |
158 | ||
159 | if (len < 10) { | |
160 | off = scnprintf(buffer, buf_len, | |
161 | "short variable length command, len=%d", | |
162 | len); | |
163 | return off; | |
164 | } | |
165 | sa = (cdbp[8] << 8) + cdbp[9]; | |
166 | } else | |
167 | sa = cdbp[1] & 0x1f; | |
168 | ||
169 | if (!scsi_opcode_sa_name(cdb0, sa, &cdb_name, &sa_name)) { | |
170 | if (cdb_name) | |
171 | off = scnprintf(buffer, buf_len, "%s", cdb_name); | |
172 | else { | |
173 | off = scnprintf(buffer, buf_len, "opcode=0x%x", cdb0); | |
174 | if (WARN_ON(off >= buf_len)) | |
175 | return off; | |
176 | if (cdb0 >= VENDOR_SPECIFIC_CDB) | |
177 | off += scnprintf(buffer + off, buf_len - off, | |
178 | " (vendor)"); | |
179 | else if (cdb0 >= 0x60 && cdb0 < 0x7e) | |
180 | off += scnprintf(buffer + off, buf_len - off, | |
181 | " (reserved)"); | |
182 | } | |
183 | } else { | |
184 | if (sa_name) | |
185 | off = scnprintf(buffer, buf_len, "%s", sa_name); | |
186 | else if (cdb_name) | |
187 | off = scnprintf(buffer, buf_len, "%s, sa=0x%x", | |
188 | cdb_name, sa); | |
189 | else | |
190 | off = scnprintf(buffer, buf_len, | |
191 | "opcode=0x%x, sa=0x%x", cdb0, sa); | |
192 | } | |
193 | WARN_ON(off >= buf_len); | |
194 | return off; | |
195 | } | |
196 | ||
197 | size_t __scsi_format_command(char *logbuf, size_t logbuf_len, | |
198 | const unsigned char *cdb, size_t cdb_len) | |
199 | { | |
200 | int len, k; | |
201 | size_t off; | |
202 | ||
203 | off = scsi_format_opcode_name(logbuf, logbuf_len, cdb); | |
204 | if (off >= logbuf_len) | |
205 | return off; | |
206 | len = scsi_command_size(cdb); | |
207 | if (cdb_len < len) | |
208 | len = cdb_len; | |
209 | /* print out all bytes in cdb */ | |
210 | for (k = 0; k < len; ++k) { | |
211 | if (off > logbuf_len - 3) | |
212 | break; | |
213 | off += scnprintf(logbuf + off, logbuf_len - off, | |
214 | " %02x", cdb[k]); | |
215 | } | |
216 | return off; | |
217 | } | |
218 | EXPORT_SYMBOL(__scsi_format_command); | |
219 | ||
220 | void scsi_print_command(struct scsi_cmnd *cmd) | |
221 | { | |
9e5ed2a5 HR |
222 | int k; |
223 | char *logbuf; | |
224 | size_t off, logbuf_len; | |
225 | ||
226 | if (!cmd->cmnd) | |
227 | return; | |
228 | ||
229 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
230 | if (!logbuf) | |
231 | return; | |
232 | ||
21045519 HR |
233 | off = sdev_format_header(logbuf, logbuf_len, |
234 | scmd_name(cmd), cmd->request->tag); | |
9e5ed2a5 HR |
235 | if (off >= logbuf_len) |
236 | goto out_printk; | |
237 | off += scnprintf(logbuf + off, logbuf_len - off, "CDB: "); | |
238 | if (WARN_ON(off >= logbuf_len)) | |
239 | goto out_printk; | |
240 | ||
241 | off += scsi_format_opcode_name(logbuf + off, logbuf_len - off, | |
242 | cmd->cmnd); | |
243 | if (off >= logbuf_len) | |
244 | goto out_printk; | |
245 | ||
246 | /* print out all bytes in cdb */ | |
247 | if (cmd->cmd_len > 16) { | |
248 | /* Print opcode in one line and use separate lines for CDB */ | |
249 | off += scnprintf(logbuf + off, logbuf_len - off, "\n"); | |
2fc583c4 | 250 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
9e5ed2a5 HR |
251 | scsi_log_release_buffer(logbuf); |
252 | for (k = 0; k < cmd->cmd_len; k += 16) { | |
253 | size_t linelen = min(cmd->cmd_len - k, 16); | |
254 | ||
255 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
256 | if (!logbuf) | |
257 | break; | |
21045519 HR |
258 | off = sdev_format_header(logbuf, logbuf_len, |
259 | scmd_name(cmd), | |
9e5ed2a5 HR |
260 | cmd->request->tag); |
261 | if (!WARN_ON(off > logbuf_len - 58)) { | |
262 | off += scnprintf(logbuf + off, logbuf_len - off, | |
263 | "CDB[%02x]: ", k); | |
264 | hex_dump_to_buffer(&cmd->cmnd[k], linelen, | |
265 | 16, 1, logbuf + off, | |
266 | logbuf_len - off, false); | |
267 | } | |
2fc583c4 | 268 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", |
9e5ed2a5 HR |
269 | logbuf); |
270 | scsi_log_release_buffer(logbuf); | |
271 | } | |
272 | return; | |
273 | } | |
274 | if (!WARN_ON(off > logbuf_len - 49)) { | |
275 | off += scnprintf(logbuf + off, logbuf_len - off, " "); | |
276 | hex_dump_to_buffer(cmd->cmnd, cmd->cmd_len, 16, 1, | |
277 | logbuf + off, logbuf_len - off, | |
278 | false); | |
279 | } | |
280 | out_printk: | |
2fc583c4 | 281 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
9e5ed2a5 HR |
282 | scsi_log_release_buffer(logbuf); |
283 | } | |
284 | EXPORT_SYMBOL(scsi_print_command); | |
21045519 HR |
285 | |
286 | static size_t | |
287 | scsi_format_extd_sense(char *buffer, size_t buf_len, | |
288 | unsigned char asc, unsigned char ascq) | |
289 | { | |
290 | size_t off = 0; | |
291 | const char *extd_sense_fmt = NULL; | |
292 | const char *extd_sense_str = scsi_extd_sense_format(asc, ascq, | |
293 | &extd_sense_fmt); | |
294 | ||
295 | if (extd_sense_str) { | |
296 | off = scnprintf(buffer, buf_len, "Add. Sense: %s", | |
297 | extd_sense_str); | |
298 | if (extd_sense_fmt) | |
299 | off += scnprintf(buffer + off, buf_len - off, | |
300 | "(%s%x)", extd_sense_fmt, ascq); | |
301 | } else { | |
302 | if (asc >= 0x80) | |
303 | off = scnprintf(buffer, buf_len, "<<vendor>>"); | |
304 | off += scnprintf(buffer + off, buf_len - off, | |
305 | "ASC=0x%x ", asc); | |
306 | if (ascq >= 0x80) | |
307 | off += scnprintf(buffer + off, buf_len - off, | |
308 | "<<vendor>>"); | |
309 | off += scnprintf(buffer + off, buf_len - off, | |
310 | "ASCQ=0x%x ", ascq); | |
311 | } | |
312 | return off; | |
313 | } | |
314 | ||
315 | static size_t | |
316 | scsi_format_sense_hdr(char *buffer, size_t buf_len, | |
317 | const struct scsi_sense_hdr *sshdr) | |
318 | { | |
319 | const char *sense_txt; | |
320 | size_t off; | |
321 | ||
322 | off = scnprintf(buffer, buf_len, "Sense Key : "); | |
323 | sense_txt = scsi_sense_key_string(sshdr->sense_key); | |
324 | if (sense_txt) | |
325 | off += scnprintf(buffer + off, buf_len - off, | |
326 | "%s ", sense_txt); | |
327 | else | |
328 | off += scnprintf(buffer + off, buf_len - off, | |
329 | "0x%x ", sshdr->sense_key); | |
330 | off += scnprintf(buffer + off, buf_len - off, | |
331 | scsi_sense_is_deferred(sshdr) ? "[deferred] " : "[current] "); | |
332 | ||
333 | if (sshdr->response_code >= 0x72) | |
334 | off += scnprintf(buffer + off, buf_len - off, "[descriptor] "); | |
335 | return off; | |
336 | } | |
337 | ||
338 | static void | |
339 | scsi_log_dump_sense(const struct scsi_device *sdev, const char *name, int tag, | |
340 | const unsigned char *sense_buffer, int sense_len) | |
341 | { | |
342 | char *logbuf; | |
343 | size_t logbuf_len; | |
344 | int i; | |
345 | ||
346 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
347 | if (!logbuf) | |
348 | return; | |
349 | ||
350 | for (i = 0; i < sense_len; i += 16) { | |
351 | int len = min(sense_len - i, 16); | |
352 | size_t off; | |
353 | ||
354 | off = sdev_format_header(logbuf, logbuf_len, | |
355 | name, tag); | |
356 | hex_dump_to_buffer(&sense_buffer[i], len, 16, 1, | |
357 | logbuf + off, logbuf_len - off, | |
358 | false); | |
2fc583c4 | 359 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
360 | } |
361 | scsi_log_release_buffer(logbuf); | |
362 | } | |
363 | ||
364 | static void | |
365 | scsi_log_print_sense_hdr(const struct scsi_device *sdev, const char *name, | |
366 | int tag, const struct scsi_sense_hdr *sshdr) | |
367 | { | |
368 | char *logbuf; | |
369 | size_t off, logbuf_len; | |
370 | ||
371 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
372 | if (!logbuf) | |
373 | return; | |
374 | off = sdev_format_header(logbuf, logbuf_len, name, tag); | |
375 | off += scsi_format_sense_hdr(logbuf + off, logbuf_len - off, sshdr); | |
2fc583c4 | 376 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
377 | scsi_log_release_buffer(logbuf); |
378 | ||
379 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
380 | if (!logbuf) | |
381 | return; | |
382 | off = sdev_format_header(logbuf, logbuf_len, name, tag); | |
383 | off += scsi_format_extd_sense(logbuf + off, logbuf_len - off, | |
384 | sshdr->asc, sshdr->ascq); | |
2fc583c4 | 385 | dev_printk(KERN_INFO, &sdev->sdev_gendev, "%s", logbuf); |
21045519 HR |
386 | scsi_log_release_buffer(logbuf); |
387 | } | |
388 | ||
389 | static void | |
390 | scsi_log_print_sense(const struct scsi_device *sdev, const char *name, int tag, | |
391 | const unsigned char *sense_buffer, int sense_len) | |
392 | { | |
393 | struct scsi_sense_hdr sshdr; | |
394 | ||
395 | if (scsi_normalize_sense(sense_buffer, sense_len, &sshdr)) | |
396 | scsi_log_print_sense_hdr(sdev, name, tag, &sshdr); | |
397 | else | |
398 | scsi_log_dump_sense(sdev, name, tag, sense_buffer, sense_len); | |
399 | } | |
400 | ||
401 | /* | |
402 | * Print normalized SCSI sense header with a prefix. | |
403 | */ | |
404 | void | |
405 | scsi_print_sense_hdr(const struct scsi_device *sdev, const char *name, | |
406 | const struct scsi_sense_hdr *sshdr) | |
407 | { | |
408 | scsi_log_print_sense_hdr(sdev, name, -1, sshdr); | |
409 | } | |
410 | EXPORT_SYMBOL(scsi_print_sense_hdr); | |
411 | ||
412 | /* Normalize and print sense buffer with name prefix */ | |
413 | void __scsi_print_sense(const struct scsi_device *sdev, const char *name, | |
414 | const unsigned char *sense_buffer, int sense_len) | |
415 | { | |
416 | scsi_log_print_sense(sdev, name, -1, sense_buffer, sense_len); | |
417 | } | |
418 | EXPORT_SYMBOL(__scsi_print_sense); | |
419 | ||
420 | /* Normalize and print sense buffer in SCSI command */ | |
421 | void scsi_print_sense(const struct scsi_cmnd *cmd) | |
422 | { | |
423 | scsi_log_print_sense(cmd->device, scmd_name(cmd), cmd->request->tag, | |
424 | cmd->sense_buffer, SCSI_SENSE_BUFFERSIZE); | |
425 | } | |
426 | EXPORT_SYMBOL(scsi_print_sense); | |
026f8da8 HR |
427 | |
428 | void scsi_print_result(const struct scsi_cmnd *cmd, const char *msg, | |
429 | int disposition) | |
430 | { | |
431 | char *logbuf; | |
432 | size_t off, logbuf_len; | |
433 | const char *mlret_string = scsi_mlreturn_string(disposition); | |
434 | const char *hb_string = scsi_hostbyte_string(cmd->result); | |
435 | const char *db_string = scsi_driverbyte_string(cmd->result); | |
436 | ||
437 | logbuf = scsi_log_reserve_buffer(&logbuf_len); | |
438 | if (!logbuf) | |
439 | return; | |
440 | ||
441 | off = sdev_format_header(logbuf, logbuf_len, | |
442 | scmd_name(cmd), cmd->request->tag); | |
443 | ||
444 | if (off >= logbuf_len) | |
445 | goto out_printk; | |
446 | ||
447 | if (msg) { | |
448 | off += scnprintf(logbuf + off, logbuf_len - off, | |
449 | "%s: ", msg); | |
450 | if (WARN_ON(off >= logbuf_len)) | |
451 | goto out_printk; | |
452 | } | |
453 | if (mlret_string) | |
454 | off += scnprintf(logbuf + off, logbuf_len - off, | |
455 | "%s ", mlret_string); | |
456 | else | |
457 | off += scnprintf(logbuf + off, logbuf_len - off, | |
458 | "UNKNOWN(0x%02x) ", disposition); | |
459 | if (WARN_ON(off >= logbuf_len)) | |
460 | goto out_printk; | |
461 | ||
462 | off += scnprintf(logbuf + off, logbuf_len - off, "Result: "); | |
463 | if (WARN_ON(off >= logbuf_len)) | |
464 | goto out_printk; | |
465 | ||
466 | if (hb_string) | |
467 | off += scnprintf(logbuf + off, logbuf_len - off, | |
468 | "hostbyte=%s ", hb_string); | |
469 | else | |
470 | off += scnprintf(logbuf + off, logbuf_len - off, | |
471 | "hostbyte=0x%02x ", host_byte(cmd->result)); | |
472 | if (WARN_ON(off >= logbuf_len)) | |
473 | goto out_printk; | |
474 | ||
475 | if (db_string) | |
476 | off += scnprintf(logbuf + off, logbuf_len - off, | |
477 | "driverbyte=%s", db_string); | |
478 | else | |
479 | off += scnprintf(logbuf + off, logbuf_len - off, | |
480 | "driverbyte=0x%02x", driver_byte(cmd->result)); | |
481 | out_printk: | |
2fc583c4 | 482 | dev_printk(KERN_INFO, &cmd->device->sdev_gendev, "%s", logbuf); |
026f8da8 HR |
483 | scsi_log_release_buffer(logbuf); |
484 | } | |
485 | EXPORT_SYMBOL(scsi_print_result); |