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